PostgreSQL pg_stat_activity pokazuje COMMIT

11

Niedawno zastąpiliśmy nasz serwer bazy danych ulepszoną maszyną z 4 x czterordzeniowymi procesorami i 32 GB pamięci RAM. Zmieniliśmy również przeznaczenie naszego starego urządzenia, aby służyło jako urządzenie podrzędne z replikacją strumieniową. Na obu urządzeniach działa CentOS 6.3 i PostgreSQL 9.2. Postgres jest jedyną rzeczą działającą na każdym z pudeł.

Ta konfiguracja istnieje od około miesiąca, kiedy nagle zaczęły się pojawiać problemy, gdy ruch zaczął się zwiększać. To, co zaczęliśmy widzieć, to czasami bardzo duże obciążenie procesora (góra pokazuje średnie obciążenie 270), a kiedy możemy spojrzeć pg_stat_activity, zobaczymy, że większość naszych połączeń jest w COMMITstanie. Pozostawienie go w spokoju skończy się, a system zacznie reagować na połączenia IDLE. Próbowaliśmy wyłączyć replikację, aby sprawdzić, czy to może być problem, ale problem nadal występuje.

Próbowaliśmy zdiagnozować, co się dzieje, i jesteśmy trochę zagubieni. Dane wyjściowe z uruchamiania perfpokazują coś podobnego do poniższego i nie mam pojęcia, co 0x347ba9reprezentuje.

+  41.40%       48154  postmaster  0x347ba9         f 0x347ba9                                   ◆
+   9.55%       10956  postmaster  0x2dc820         f set_config_option                          ▒
+   8.64%        9946  postmaster  0x5a3d4          f writeListPage     
+   5.75%        6609  postmaster  0x5a2b0          f ginHeapTupleFastCollect                    ▒
+   2.68%        3084  postmaster  0x192483         f build_implied_join_equality                ▒
+   2.61%        2990  postmaster  0x187a55         f build_paths_for_OR                         ▒
+   1.86%        2131  postmaster  0x794aa          f get_collation_oid                          ▒
+   1.56%        1822  postmaster  0x5a67e          f ginHeapTupleFastInsert                     ▒
+   1.53%        1766  postmaster  0x1929bc         f distribute_qual_to_rels                    ▒
+   1.33%        1558  postmaster  0x249671         f cmp_numerics

Żadne z zapytań wykonywanych przez aplikację nie jest szczególnie złożone, a wyjaśnienie planów zajmuje maksymalnie 1 sekundę (większość jest znacznie szybsza). Ponadto, chociaż dzieje się tak, gdy ruch zaczyna się zwiększać, nie mówimy o dużym obciążeniu ruchem (stara maszyna była w stanie dość łatwo sobie z tym poradzić).

W tym momencie jestem trochę zakłopotany tym, co spróbować dalej. Każda pomoc lub sugestie będą mile widziane. Jeśli są jakieś dodatkowe informacje, które mogłyby pomóc, po prostu zapytaj, a ja mogę zmienić pytanie.

Konfiguracja dysku:

  • Kontroler RAID Perc 6i
  • 5 dysków 146 GB SAS 15 GB
  • Skonfigurowany jako 2x146GB RAID-1 dla WAL i 3x146GB RAID-5 dla Systemu i danych

Aktualizacja:

Poniżej znajduje się wyjście VMStat, gdy system działa normalnie i gdy procesor wystrzeliwuje. Kiedy pojawia się problem, przerwania wydają się gwałtownie rosnąć.

Podczas normalnej pracy:

procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu------ ---timestamp---
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 0  0      0 18938590 303763 21947154    0    0    28    52 7466 12649  2  1 97  0  0   2013-01-14 16:03:25 EST
 0  0      0 18938396 303763 21947154    0    0     0    19 7107 12679  2  0 98  0  0   2013-01-14 16:03:35 EST
 1  0      0 18938904 303763 21947162    0    0     0    54 7042 12708  1  1 99  0  0   2013-01-14 16:03:45 EST
 1  0      0 18938520 303763 21947260    0    0    33    66 7120 12738  1  1 99  0  0   2013-01-14 16:03:55 EST

Gdy użycie procesora jest wysokie:

procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu------ ---timestamp---
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
343 0      0 32680468 226279 11339612    0    0     0   214 26692 12225 80  20  0  0  0   2013-01-11 16:45:53 EST
374 1      0 32673764 226291 11340345    0    0     0    77 54893 11572 80  20  0  0  0   2013-01-11 16:46:03 EST
383 0      0 32616620 226304 11340956    0    0     0   102 55540 12922 82  18  0  0  0   2013-01-11 16:46:13 EST
315 0      0 32602038 226320 11341378    0    0     0    79 54539 12441 82  18  0  0  0   2013-01-11 16:46:23 EST
postgresql jcern
źródło
Jakie dyski ma nowe pudełko? Czy dzieje się tak na obu węzłach, czy tylko na jednym z nich?
Trygve Laugstøl
@trygvis - Zaktualizowałem pytanie o specyfikację dysku. Problem występuje w węźle głównym. Nie próbowałem promować Slave i kierować do niego ruchu, więc nie jestem pewien, czy jest to problem również w tych samych okolicznościach. Jako niewolnik wydaje się, że maszyna nie napotyka żadnych problemów.
jcern
2
Zastanów się nad użyciem tego perfnarzędzia do profilowania całego systemu i niektórych profili PostgreSQL. Zobacz, gdzie występuje użycie procesora. BTW, formatowanie drugiego vmstatjest beznadziejnie zniekształcone, a kolumny pierwszego są źle wyrównane, więc trudno jest je odczytać. Sprawdź, czy dodanie commit_delaypoprawia rzeczy. Sprawdź, czy kontroler RAID ma pamięć podręczną zapisu z podtrzymaniem bateryjnym, a jeśli nie, zdobądź ją. Czy spędzasz dużo czasu iowait? W niektórych raportach wygląda to na użycie procesora, ale tak naprawdę nie jest.
Craig Ringer
@CraigRinger kontroler ma pamięć podręczną zapisu z podtrzymaniem bateryjnym, która jest obecnie włączona. Oczekiwanie od iostatu pozostało od pojedynczej do niskiej podwójnej cyfry. Będziemy nadal próbować trochę więcej profilowania za pomocą perf. Poprawiłem także formatowanie drugiego VMStat, dziękuję za zwrócenie na to uwagi.
jcern

Odpowiedzi:

11

Po dalszej diagnostyce i trochę googlingu natknęliśmy się na ten artykuł opisujący wiele takich samych symptomów, których doświadczamy. Podstawowa przyczyna ich problemu (i z tego, co możemy powiedzieć, również nasz) była związana z Transparent Huge Pageswdrożeniem.

Po wyłączeniu za Transparent Huge Pagespomocą tego polecenia:

echo never > /sys/kernel/mm/redhat_transparent_hugepage/enabled

Wygląda na to, że problem został rozwiązany. Przez ostatnie dwa tygodnie pracowaliśmy pod zwiększonym obciążeniem i problem nie pojawił się ponownie. Konteksty systemu i przerwania są konsekwentnie 1/10 tego, czym były, a także skrócił się średni czas systemu.

Nie jestem pewien, czy jest to rozwiązanie dla wszystkich, ale zamieszczam je tutaj jako możliwą przyczynę, na wypadek gdyby ktoś inny mógł rozwiązać podobny problem.

jcern
źródło