Instalujemy Linuksa (jest na Amazon AWS, systemie podobnym do CentOS, chociaż nie jesteśmy do końca pewni, czy wykonane w nim dostosowania) na 4 GB pamięci jako wolumin XFS ponad LVM (ostatecznie ma być używany do obsługi przez NFS4, ale jest jeszcze nieużywany), a my używamy rsync do synchronizacji plików z naszego produkcyjnego serwera NFS z woluminem XFS (tzn. synchronizujemy ze źródła przez NFS do lokalnie zamontowanego woluminu LVM opartego na XFS). Zauważyliśmy jednak, że w pewnym momencie rsync zaczął być coraz wolniejszy (gwałtownie zmniejszona przepustowość), a zarówno średnie obciążenie, jak i zużycie pamięci znacznie wzrosły (a procesor ma bardzo duży udział w iowait). W końcu zrestartowałem system XFS i system najwyraźniej powrócił do normalności, z bardziej normalną wydajnością rsync od co najmniej ostatnich 24 godzin.
Sprawdziliśmy wykresy monitorowania Munina i nie zauważyliśmy niczego oczywistego, ale stwierdziliśmy, że metryki „Rozmiar tabeli i-węzłów” i „Otwórz i-węzeł” (sprawdziliśmy implementację wtyczki Munin, która wskazuje na wartości jako odczytane z / proc / sys / fs / inode-nr) zmniejszał się z czasem. Krótko przed tym, jak zaobserwowaliśmy, że rsync się zacina, zauważyliśmy, że oba wskaźniki spadły do wartości kilku tysięcy z kilkuset tysięcy (nasze serwery inne niż XFS pozostają w przybliżeniu na 500k przez większość czasu i nie wykazują monotonicznego trendu spadkowego w dłuższych okresach ) i zaobserwowaliśmy dzienniki z jądra takie jak te:
ip-XX-XXX-XXX-XXX login: [395850.680006] hrtimer: przerwanie zajęło 20000573 ns 18 września 17:19:58 ip-XX-XXX-XXX-XXX jądro: [395850.680006] hrtimer: przerwanie zajęło 20000573 ns [400921.660046] INFORMACJE: zadanie rsync: 7919 zablokowane na ponad 120 sekund. [400921.660066] „echo 0> / proc / sys / kernel / hung_task_timeout_secs” wyłącza tę wiadomość. [400921.660077] rsync D ffff880002fe4240 0 7919 7918 0x00000000 [400921.660093] ffff8800683e5638 0000000000000282 ffff880000000000 0000000000014240 [400921.660131] ffff8800683e5fd8 0000000000014240 ffff8800683e5fd8 ffff88000726da40 [400921.660153] 0000000000014240 0000000000014240 ffff8800683e5fd8 0000000000014240 [400921.660176] Śledzenie połączeń: [400921.660202] [] time_timeout + 0x1fd / 0x270 [400921.660220] []? pvclock_clocksource_read + 0x58 / 0xd0 [400921.660234] []? __raw_callee_save_xen_irq_enable + 0x11 / 0x26 [400921.660247] [] __down + 0x76 / 0xc0 [400921.660262] [] w dół + 0x3b / 0x50 [400921.660274] []? _raw_spin_unlock_irqrestore + 0x19 / 0x20 [400921.660314] [] xfs_buf_lock + 0x2b / 0x80 [xfs] [400921.660338] [] _xfs_buf_find + 0x139 / 0x230 [xfs] [400921.660360] [] xfs_buf_get + 0x5b / 0x160 [xfs] [400921.660378] [] xfs_buf_read + 0x13 / 0xa0 [xfs] [400921.660401] [] xfs_trans_read_buf + 0x197 / 0x2c0 [xfs] [400921.660422] [] xfs_read_agi + 0x6f / 0x100 [xfs] [400921.660443] [] xfs_ialloc_read_agi + 0x29 / 0x90 [xfs] [400921.660467] [] xfs_ialloc_ag_select + 0x12b / 0x280 [xfs] [400921.660485] [] xfs_dialloc + 0x3c7 / 0x870 [xfs] [400921.660500] []? pvclock_clocksource_read + 0x58 / 0xd0 [400921.660509] []? __raw_callee_save_xen_restore_fl + 0x11 / 0x1e [400921.660531] [] xfs_ialloc + 0x60 / 0x6a0 [xfs] [400921.660550] []? xlog_grant_log_space + 0x39c / 0x3f0 [xfs] [400921.660566] []? xen_spin_lock + 0xa5 / 0x110 [400921.660583] [] xfs_dir_ialloc + 0x7d / 0x2d0 [xfs] [400921.660606] []? xfs_log_reserve + 0xe2 / 0xf0 [xfs] [400921.660623] [] xfs_create + 0x3f7 / 0x600 [xfs] [400921.660638] []? __raw_callee_save_xen_restore_fl + 0x11 / 0x1e [400921.660655] [] xfs_vn_mknod + 0xa2 / 0x1b0 [xfs] [400921.660678] [] xfs_vn_create + 0xb / 0x10 [xfs] [400921.660689] [] vfs_create + 0xa7 / 0xd0 [400921.660701] [] do_last + 0x529 / 0x650 [400921.660714] []? get_empty_filp + 0x75 / 0x170 [400921.660728] [] do_filp_open + 0x213 / 0x670 [400921.660744] []? xen_spin_lock + 0xa5 / 0x110 [400921.660753] []? __raw_callee_save_xen_restore_fl + 0x11 / 0x1e [400921.660769] []? przydziel_fd + 0x102 / 0x150 [400921.660780] [] do_sys_open + 0x64 / 0x130 [400921.660792] []? __raw_callee_save_xen_irq_disable + 0x11 / 0x1e [400921.660804] [] sys_open + 0x1b / 0x20 [400921.660815] [] system_call_fastpath + 0x16 / 0x1b
Zauważyliśmy również drastyczny wzrost operacji „wyszukiwania”, jak widać na źródłowym NFS, kiedy to się zdarzyło, który wcześniej pozostawał stabilny, zanim zaczęliśmy doświadczać wspomnianego problemu z rsync.
Nie zaobserwowaliśmy podobnego zachowania w przypadku naszych wielkości produkcji opartych na ext3 i faktycznie miały one jeszcze większe rozmiary. Oprócz różnic w systemie plików, serwery plików znajdują się na podobnej klasie maszyn i konfigurują w podobny sposób. Ponieważ stwierdziliśmy, że wskaźniki tabeli i-węzłów na serwerze XFS wciąż wykazują tendencję spadkową podobną do naszej wcześniejszej obserwacji, mimo że właśnie uruchomiliśmy ją wczoraj, obawiam się, że ten sam problem wkrótce nas nawiedzi i może prawdopodobnie odzwierciedlać niektóre problemy z naszą konfiguracją, jądrem lub czymkolwiek.
Jesteśmy wtedy na woluminach XFS zamontowanych na inode64 na maszynach o architekturze x86_64. W tej chwili skopiowaliśmy około 1,3 TB danych na wolumin XFS o pojemności około 4 TB i powinniśmy mieć około 3 TB danych w tym woluminie, jeśli zostaną w pełni skopiowane. Wolumin został utworzony od nowa, dlatego od samego początku był montowany inode64, gdy nie było w nim żadnych danych, dlatego system plików powinien być czysty, a i-węzły równomiernie rozmieszczone.
Jakieś spostrzeżenia, co może być przyczyną?
(ps w rzeczywistości zaczęliśmy to widzieć od kilku godzin temu!)