Potężny strace
mnie zawiódł. Jak to jest możliwe?
time foo
pokazuje, że foo
uruchomienie zajmuje kilka sekund („rzeczywisty”), ale zużywa nieznaczny czas procesora, zarówno w przestrzeni użytkownika („użytkownik”), jak i w jądrze („sys”). Dla ciekawskich foo
zdefiniowano poniżej.
Dlatego spędza większość czasu czekając na coś innego, nie wykonując instrukcji procesora. Zwykle widzę, jak czeka strace
- tzn. Jakie wywołanie systemowe blokuje przez długi czas. Niestety takie podejście nie zadziałało.
strace -ttt -T -C -w foo
pokazuje wywołania systemowe, znaczniki czasu oraz podsumowanie (rzeczywistego) czasu spędzonego na wywołaniach systemowych. Ale ten szczególny proces pokazał, że spędzanie nieistotnego czasu (w czasie rzeczywistym) wewnątrz wywołań systemowych.
foo
jest właściwie journalctl -b -u dev-hugepages.mount
. Tyle że musiałem za każdym razem zmieniać ostatni argument na inną jednostkę systemową, aby to odtworzyć. Innymi słowy, opóźnienie, które badam, zdarzyło się po raz pierwszy, gdy próbuję uzyskać dzienniki dla dowolnej jednostki systemowej. EDYCJA : po udzieleniu odpowiedzi na główne pytanie, zdałem sobie również sprawę z tego, dlaczego miałem problem z odtworzeniem opóźnienia .
Czas spędzony przez ten proces jest szczególnym problemem, najwyraźniej nie występuje we wszystkich systemach. https://github.com/systemd/systemd/issues/7963
źródło
journalctl
działa tylko jeden proces. Mam wrażenie, żejournalctl
używa jednego dodatkowego wątku z jakiegokolwiek powodu - iirc była jedna rozmowa clone (). Myślę, że oznacza to, że masz techniczną rację, ale jest to również technicznie nieistotne dla pytania.time
patrzy na proces jako całość i wykazał, że proces jako całość jest raczej senny (blokuje na czymś).strace
nie pokazał wystarczającej ilości snu. Nie ma znaczenia, czy śpi drugi wątek, główny wątek również musi być bardzo śpiący, aby wyjaśnićtime
wynik.Odpowiedzi:
Zwykle powodem tego problemu jest to, że proces blokuje błędy stron. Są to odczyty lub zapisy plików wykonywanych poprzez mapowanie pamięci aka
mmap()
. Być może zauważyłeś pewnemmap()
ślady wywołań systemowych.Jeśli używałeś
/usr/bin/time
programu zamiasttime
wbudowanej powłoki, mógłbyś również zauważyć:major
błędy strony są tymi, które wymagają IO systemu plików.minor
błędy strony są znacznie mniej znaczące (prawdopodobnie tylko „brak TLB”).Podejrzewam, że
inputs
to całkowita liczba przeczytanych stron. Obecnie uważam, że strony mapowane na plik mają zawsze ten sam rozmiar. 4096 bajtów w większości przypadków, ale można to sprawdzićgetconf PAGESIZE
.Oznacza to ~ 290 megabajtów, odczyt z prędkością ponad 100 megabajtów na sekundę, standardową prędkością dla dysku twardego takiego jak mój. Zagadka rozwiązana!
Pamiętaj również, że zakładasz, że masz cały wolny procesor dla tego procesu. W przeciwnym razie proces można po prostu zablokować, czekając, aż inne procesy zwrócą CPU.
strace
pokazuje tylko, kiedy proces wchodzi do jądra (a następnie opuszcza go) z powodu wywołania systemowego. Lub gdy dostarczany jest sygnał uniksowy. Istnieją jednak inne rodzaje przerwań, którestrace
ogóle się nie wyświetlają. Więc to obejmujeźródło