psql: FATAL: przepraszam, już za dużo klientów

16

Nagle pojawia się ten błąd podczas próby uzyskania dostępu do strony internetowej korzystającej z bazy danych postgresql lub nawet podczas korzystania z narzędzia psql lub pgadmin3.

Moja baza danych jest ustawiona na obsługę 150 maksymalnych połączeń:

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

Po ponownym uruchomieniu serwera Ubuntu, na którym znajduje się moja strona internetowa (co tak naprawdę jest jedyną rzeczą używającą połączeń), widzę, że obecna liczba połączeń wynosi 140:

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

Nie rozumiem, jak nagle tak wiele połączeń po ponownym uruchomieniu mojego serwera. Sprawdzam więc aktywność postgresql:

# SELECT * FROM pg_stat_activity;

I widzę ponad 100 kolumn z dokładnie tym samym zapytaniem, które wygląda tak:

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

Jeszcze ważniejsze jest to, że wszystkie mają ten sam adres klienta (mój serwer WWW).

Ten serwer WWW używa ruby ​​na szynach z pulą połączeń 50. Nawet jeśli istnieje pula połączeń 50, konfiguracja procesu pasażera / apache prefork jest jednowątkowa, a zatem każdy proces nie może spawnować 50 wątków i 50 połączeń z bazą danych. Co więcej, stało się to po ponownym uruchomieniu systemu, który powalił wszystkich użytkowników z mojego serwera WWW. Prawdopodobieństwo, że postgresql na serwerze bazy danych nie jest świadomy ponownego uruchomienia serwera WWW i nadal próbuje wykonać te zapytania.

Aby odpowiedzieć na komentarze Craiga, pod kolumną oczekiwania wyświetla się litera „f”. Wygląda na to, że zapytanie jest nadal wykonywane i blokada nie została jeszcze zwolniona. Jak już wcześniej powiedziałem, tak dziwne jest to, że nagle w tym stanie wykonania pojawiło się nagle ponad 100 identycznych zapytań w odstępie milisekund. To dla mnie tajemnica:

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
źródło
Spójrz na pg_stat_activity.backend_start. Czy te połączenia zostały utworzone przed ponownym uruchomieniem serwera WWW? Jeśli wszystkie są nowymi połączeniami, wyobrażam sobie, że oznacza to, że problem leży po stronie serwera WWW.
Nick Barnes
@NickBarnes wszystkie połączenia mają tę samą kwerendę w kolumnie „current_query”, a czas backend_start jest praktycznie taki sam dla wszystkich (w milisekundach). To jest takie dziwne i wierzę, że jeśli pamięć służy mi poprawnie, wszystkie były przed restartem. Ale założyłem, że ponowne uruchomienie przerwie połączenie.
JohnMerlino
1
Ok ... Może być konieczne sprawdzenie topna serwerze, czy te procesy są zajęte. Jeśli tak, to myślę, że połączenia powinny zniknąć po zakończeniu zapytań (lub alternatywnie, możesz je teraz zabić). Jeśli są bezczynne, a połączenia są zdecydowanie martwe, to nie jestem pewien, co się dzieje ani jak temu zapobiec następnym razem ...
Nick Barnes
1
Sprawdź waitingflagę pg_stat_activityi sprawdź, czy utknęły na zamku.
Craig Ringer
1
Wyniki, które wkleiłeś, SELECT * FROM pg_stat_activity;nie są wiarygodne - nie ma wystarczającej liczby kolumn. Co mówi kolumna stanu? To najważniejsze pole dla tego pytania.
eradman

Odpowiedzi:

5

Wydaje się, że jest to specyficzny problem z programowaniem klienta. Nie będziesz w stanie tego naprawić, np. Podnosząc parametr „max_connections”.

Znalazłem możliwy powiązany problem: pula połączeń z bazą danych Ruby

Mimo wszystko Możesz także wykonać więcej debugowania po stronie serwera:

Włącz „log_connections” i „log_disconnections”. Użyj również „log_line_prefix” z „% m% a% p”.

Bardzo przydatne aplikacje do debugowania serwerów PostgreSQL są powa lub znacznie więcej takich jak: pg_activity

Do debugowania serwera w czasie rzeczywistym wolę pg_activity - zwłaszcza z funkcją wyświetlania blokerów i zabijania sesji.

Josef Hopfgartner
źródło
-4

To najlepszy sposób na rozwiązanie problemu ... działa

Zaloguj się do serwera za pomocą SSH Kit,

sudo /etc/init.d/postgresql stop

to zabija procesy martwego dziennika w bazie danych,

sudo /etc/init.d/postgresql start

Maduka
źródło
6
A potem następnym razem zatrzymasz serwer produkcyjny? Twoje rozwiązanie wyraźnie usuwa zablokowane procesy, ale nie wyjaśnia, dlaczego one istnieją, ani nie jest zrównoważone.
dezso,