Wysokie obciążenie serwera - [jbd2 / md1-8] przy użyciu 99,99% IO

12

Przez ostatni tydzień miałem gwałtowny wzrost obciążenia. Zwykle dzieje się to raz lub dwa razy dziennie. Udało mi się ustalić z iotop, że [jbd2 / md1-8] używa 99,99% IO. W czasie dużego obciążenia nie ma dużego ruchu do serwera.

Specyfikacja serwera to:

  • Rdzeń AMD Opteron 8
  • 16 GB pamięci RAM
  • 2x2.000 GB 7.200 RPM HDD Software Raid 1
  • Cloudlinux + Cpanel
  • MySQL jest odpowiednio dostrojony

Oprócz kolców obciążenie zwykle wynosi najwyżej około 0,80.

Szukałem w okolicy, ale nie mogę znaleźć, co dokładnie robi [jbd2 / md1-8]. Czy ktoś miał ten problem lub ktoś zna możliwe rozwiązanie?

Dziękuję Ci.

AKTUALIZACJA:

TIME        TID     PRIO     USER    DISK READ    DISK WRITE    SWAPIN  IO       COMMAND
16:05:36     399     be/3    root    0.00 B/s      38.76 K/s    0.00 %  99.99 %  [jbd2/md1-8]
Alex
źródło
1
en.wikipedia.org/wiki/Journaling_block_device & linux.die.net/man/4/md wskazują, że jest to związane z oprogramowaniem RAID.
mbrownnyc
Dzięki za odpowiedź. Po kilku kopaniach odkryłem, że jest to związane z oprogramowaniem RAID. Czy znasz jakieś rozwiązanie? Dziwna rzecz, która zaczęła się dziać tydzień temu, po prawie 3 miesiącach bez problemów.
Alex
Jak ustaliłeś, że IO wynosi 99,99%? Czy używałeś iostat? Czy możesz trochę uruchomić (powiedzmy iostat 5) trochę i podzielić się wynikami?
slm
Włączyłem rejestrowanie dla iotop i sprawdziłem dziennik dla okresu, w którym wystąpiło ładowanie. Teraz obciążenie jest niskie, więc nie ma sensu go teraz uruchamiać, ale zrobię to następnym razem. Dzięki za odpowiedź.
Alex
1
Właśnie natrafiłem na ten konkretny problem. Jakie było Twoje ostateczne rozwiązanie?
Satanicpuppy

Odpowiedzi:

18

To nie jest tak naprawdę odpowiedź, ponieważ nie ma wystarczającego kontekstu, aby podać dokładną przyczynę, ale jest to opis tego, jak udało mi się to śledzić, kiedy mi się to przydarzyło.

Zauważyłem, że jbd2/md0-8ciągle pojawiałem się na górze iotop. Zajrzałem, /sys/kernel/debug/tracing/events/jbd2żeby zobaczyć, jakie są opcje, aby ustalić, co się jbd2dzieje.

UWAGA-1: Aby wyświetlić dane wyjściowe dla zdarzeń śledzenia debugowania cat /sys/kernel/debug/tracing/trace_pipe- miałem to uruchomione w terminalu podczas włączania / wyłączania śledzenia.

UWAGA-2: Aby włączyć zdarzenia do śledzenia, użyj np echo 1 > /sys/kernel/debug/tracing/events/jbd2/jbd2_run_stats/enable. Aby wyłączyć echo 0 > /sys/kernel/debug/tracing/events/jbd2/jbd2_run_stats/enable.

Zacząłem od włączenia /sys/kernel/debug/tracing/events/jbd2/jbd2_run_stats/enable- ale nie było w nim nic, co wydawałoby się szczególnie interesujące. Próbowałem śledzić kilka innych zdarzeń, a gdy włączyłem /sys/kernel/debug/tracing/events/jbd2/jbd2_commit_flushing/enable, zauważyłem, że następują one co sekundę:

# cat /sys/kernel/debug/tracing/trace_pipe
...
jbd2/md0-8-2520  [004] .... 658660.216492: jbd2_commit_flushing: dev 9,0 transaction 32856413 sync 0
jbd2/md0-8-2520  [001] .... 658661.334900: jbd2_commit_flushing: dev 9,0 transaction 32856414 sync 0
jbd2/md0-8-2520  [001] .... 658661.394113: jbd2_commit_flushing: dev 9,0 transaction 32856415 sync 0

Wyglądało to tak, jakby było powiązane z sync(2)/ fsync(2)/ msync(2), więc szukałem sposobu, aby połączyć to z procesem i znalazłem to:

# find /sys/kernel/debug/tracing/events/ | grep sync.*enable
...
/sys/kernel/debug/tracing/events/ext4/ext4_sync_file_enter/enable
...

Po włączeniu zobaczyłem następujące dane wyjściowe:

# cat /sys/kernel/debug/tracing/trace_pipe
...
      nzbget-17367 [002] .... 658693.222288: ext4_sync_file_enter: dev 9,0 ino 301924373 parent 301924357 datasync 1 
  jbd2/md0-8-2520  [001] .... 658693.284080: jbd2_commit_flushing: dev 9,0 transaction 32856465 sync 0
      nzbget-17367 [000] .... 658693.334267: ext4_sync_file_enter: dev 9,0 ino 301924357 parent 301924353 datasync 1 
  jbd2/md0-8-2520  [002] .... 658693.334275: jbd2_commit_flushing: dev 9,0 transaction 32856466 sync 0
      nzbget-17367 [001] .... 658694.369514: ext4_sync_file_enter: dev 9,0 ino 301924367 parent 301924357 datasync 1 
  jbd2/md0-8-2520  [002] .... 658694.414861: jbd2_commit_flushing: dev 9,0 transaction 32856467 sync 0
      nzbget-17367 [001] .... 658694.470872: ext4_sync_file_enter: dev 9,0 ino 301924357 parent 301924353 datasync 1 
  jbd2/md0-8-2520  [002] .... 658694.470880: jbd2_commit_flushing: dev 9,0 transaction 32856468 sync 0

To dało mi nazwę / identyfikator procesu - i po kilku debugowaniu tego procesu ( nzbget) odkryłem, że robi to fsync(2)co sekundę. Po zmianie konfiguracji ( FlushQueue=nomyślę, że nieudokumentowane, znalazłem ją w źródle), aby powstrzymać się od robienia tego na sekundę, fsync(2)problem zniknął.

Moja wersja jądra to. 4.4.6-gentooMyślę, że były pewne opcje, które włączyłem (ręcznie lub za pomocą make oldconfig) w pewnym momencie konfiguracji jądra, aby uzyskać /sys/kernel/debugte zdarzenia - więc jeśli nie masz, może po prostu rozejrzyj się po Internecie, aby uzyskać więcej informacji na temat włączania to.

Iwan Aucamp
źródło
Niezły śpioch. To jest bardzo pomocne.
jdhildeb
Wielkie dzięki za opisanie całego procesu!
astrojuanlu
1

To wydaje się być związane z aktualizacją dziennika. Ile dysków składa się z oprogramowania RAID. Czy możesz mi pokazać polecenie użyte do jego utworzenia.

Czy możesz również wkleić dane wyjściowe dumpe2fs. Najpierw zidentyfikuj urządzenie fizyczne, w którym widzisz obciążenie. Użyj df, aby to wiedzieć. Następnie,

dumpe2fs /dev/sdaX > /tmp/dump

W twoim przypadku może to być / dev / md0.

Uruchom także to.

iostat -xdk 1 25

W momencie wysokiego problemu z IO.

Nie znam cloudlinux, ale jest dostępne narzędzie blktrace.

Soham Chakraborty
źródło
Cześć Soham, dziękuję za odpowiedź. W macierzy są 2 dyski. Jeśli chodzi o dumpe2fs, czy możesz podać mi pełne polecenie, które chcesz, żebym uruchomił? Dzięki za pomoc.
Alex
Alex zredagował odpowiedź.
Soham Chakraborty
Nigdy nie zapominaj, że to nie jest tak naprawdę żadna konfiguracja w połowie płyty z płyty - „powolna jak stacja robocza” bardziej to opisuje.
TomTom