Wątek Java wykonujący pozostałą operację w pętli blokuje wszystkie inne wątki

Poniższy fragment kodu wykonuje dwa wątki, jeden to prosty licznik czasu rejestrujący co sekundę, drugi to nieskończona pętla, która wykonuje pozostałą operację:

public class TestBlockingThread {
    private static final Logger LOGGER = LoggerFactory.getLogger(TestBlockingThread.class);

    public static final void main(String[] args) throws InterruptedException {
        Runnable task = () -> {
            int i = 0;
            while (true) {
                i++;
                if (i != 0) {
                    boolean b = 1 % i == 0;
                }
            }
        };

        new Thread(new LogTimer()).start();
        Thread.sleep(2000);
        new Thread(task).start();
    }

    public static class LogTimer implements Runnable {
        @Override
        public void run() {
            while (true) {
                long start = System.currentTimeMillis();
                try {
                    Thread.sleep(1000);
                } catch (InterruptedException e) {
                    // do nothing
                }
                LOGGER.info("timeElapsed={}", System.currentTimeMillis() - start);
            }
        }
    }
}

Daje to następujący wynik:

[Thread-0] INFO  c.m.c.concurrent.TestBlockingThread - timeElapsed=1004
[Thread-0] INFO  c.m.c.concurrent.TestBlockingThread - timeElapsed=1003
[Thread-0] INFO  c.m.c.concurrent.TestBlockingThread - timeElapsed=13331
[Thread-0] INFO  c.m.c.concurrent.TestBlockingThread - timeElapsed=1006
[Thread-0] INFO  c.m.c.concurrent.TestBlockingThread - timeElapsed=1003
[Thread-0] INFO  c.m.c.concurrent.TestBlockingThread - timeElapsed=1004
[Thread-0] INFO  c.m.c.concurrent.TestBlockingThread - timeElapsed=1004

Nie rozumiem, dlaczego nieskończone zadanie blokuje wszystkie inne wątki na 13,3 sekundy. Próbowałem zmienić priorytety wątków i inne ustawienia, nic nie działało.

Jeśli masz jakieś sugestie, jak to naprawić (w tym zmiana ustawień przełączania kontekstu systemu operacyjnego), daj mi znać.

Po wszystkich wyjaśnieniach tutaj (dzięki Peter Lawrey ) odkryliśmy, że głównym źródłem tej przerwy jest to, że punkt bezpieczeństwa wewnątrz pętli jest osiągany raczej rzadko, więc zatrzymanie wszystkich wątków w celu zastąpienia kodu skompilowanego w JIT zajmuje dużo czasu.

Ale zdecydowałem się pójść głębiej i dowiedzieć się, dlaczego rzadko osiąga się bezpieczny punkt. Wydało mi się trochę zagmatwane, dlaczego skok whilepętli w tył nie jest w tym przypadku „bezpieczny”.

Wzywam więc do pomocy -XX:+PrintAssemblyw całej okazałości

-XX:+UnlockDiagnosticVMOptions \
-XX:+TraceClassLoading \
-XX:+DebugNonSafepoints \
-XX:+PrintCompilation \
-XX:+PrintGCDetails \
-XX:+PrintStubCode \
-XX:+PrintAssembly \
-XX:PrintAssemblyOptions=-Mintel

Po pewnym dochodzeniu odkryłem, że po trzeciej rekompilacji lambda C2kompilator całkowicie wyrzucił ankiety punktu bezpieczeństwa w pętli.

AKTUALIZACJA

Na etapie profilowania zmienna inigdy nie była równa 0. Dlatego też C2spekulacyjnie zoptymalizowano tę gałąź tak, aby pętla została przekształcona w coś podobnego

for (int i = OSR_value; i != 0; i++) {
    if (1 % i == 0) {
        uncommon_trap();
    }
}
uncommon_trap();

Zauważ, że pierwotnie nieskończona pętla została przekształcona w regularną skończoną pętlę z licznikiem! Ze względu na optymalizację JIT w celu wyeliminowania sondaży punktów bezpieczeństwa w pętlach o skończonej liczbie zliczania, w tej pętli nie było również sondowania punktów bezpieczeństwa.

Po jakimś czasie izawinięty z powrotem 0i niecodzienna pułapka została złapana. Metoda została odoptymalizowana i kontynuowana w tłumaczu. Podczas rekompilacji z nową wiedzą C2rozpoznał nieskończoną pętlę i zrezygnował z kompilacji. Reszta metody przebiegała w tłumaczu z odpowiednimi punktami bezpieczeństwa.

Jest świetny wpis na blogu, który trzeba przeczytać „Safepoints: Meaning, Side Effects and Overheads” autorstwa Nitsana Wakarta i ten szczególny problem.

Wiadomo, że problemem jest eliminacja punktu bezpiecznego w bardzo długich zliczanych pętlach. Błąd JDK-5014723(dzięki Vladimir Ivanov ) rozwiązuje ten problem.

Obejście jest dostępne do czasu ostatecznego naprawienia błędu.

1. Możesz spróbować użyć -XX:+UseCountedLoopSafepoints( spowoduje to ogólny spadek wydajności i może doprowadzić do awarii JVM JDK-8161147 ). Po jego użyciu C2kompilator kontynuuje przechowywanie punktów bezpieczeństwa z tyłu, skacze i oryginalna pauza znika całkowicie.

2. Możesz jawnie wyłączyć kompilację problematycznej metody przy użyciu
   -XX:CompileCommand='exclude,binary/class/Name,methodName'

3. Możesz też przepisać swój kod, dodając ręcznie bezpieczny punkt. Na przykład Thread.yield()połączenie na koniec cyklu lub nawet zmiana int ina long i(dzięki, Nitsan Wakart ) również naprawi pauzę.

Krótko mówiąc, pętla, którą masz, nie ma w sobie bezpiecznego punktu, z wyjątkiem sytuacji, gdy i == 0 zostanie osiągnięta. Gdy ta metoda jest kompilowana i wyzwala kod do zastąpienia, musi doprowadzić wszystkie wątki do bezpiecznego punktu, ale zajmuje to bardzo dużo czasu, blokując nie tylko wątek, w którym działa kod, ale wszystkie wątki w JVM.

Dodałem następujące opcje wiersza poleceń.

-XX:+PrintGCApplicationStoppedTime -XX:+PrintGCApplicationConcurrentTime -XX:+PrintCompilation

Zmodyfikowałem również kod, aby używał zmiennoprzecinkowych, co wydaje się trwać dłużej.

boolean b = 1.0 / i == 0;

I to, co widzę na wyjściu to

timeElapsed=100
Application time: 0.9560686 seconds
  41423  280 %     4       TestBlockingThread::lambda$main$0 @ -2 (27 bytes)   made not entrant
Total time for which application threads were stopped: 40.3971116 seconds, Stopping threads took: 40.3967755 seconds
Application time: 0.0000219 seconds
Total time for which application threads were stopped: 0.0005840 seconds, Stopping threads took: 0.0000383 seconds
  41424  281 %     3       TestBlockingThread::lambda$main$0 @ 2 (27 bytes)
timeElapsed=40473
  41425  282 %     4       TestBlockingThread::lambda$main$0 @ 2 (27 bytes)
  41426  281 %     3       TestBlockingThread::lambda$main$0 @ -2 (27 bytes)   made not entrant
timeElapsed=100

Uwaga: aby zastąpić kod, wątki muszą zostać zatrzymane w bezpiecznym miejscu. Okazuje się jednak, że taki bezpieczny punkt osiąga się bardzo rzadko (być może tylko przy i == 0zmianie zadania na

Runnable task = () -> {
    for (int i = 1; i != 0 ; i++) {
        boolean b = 1.0 / i == 0;
    }
};

Widzę podobne opóźnienie.

timeElapsed=100
Application time: 0.9587419 seconds
  39044  280 %     4       TestBlockingThread::lambda$main$0 @ -2 (28 bytes)   made not entrant
Total time for which application threads were stopped: 38.0227039 seconds, Stopping threads took: 38.0225761 seconds
Application time: 0.0000087 seconds
Total time for which application threads were stopped: 0.0003102 seconds, Stopping threads took: 0.0000105 seconds
timeElapsed=38100
timeElapsed=100

Dodając kod do pętli ostrożnie, uzyskujesz większe opóźnienie.

for (int i = 1; i != 0 ; i++) {
    boolean b = 1.0 / i / i == 0;
}

dostaje

 Total time for which application threads were stopped: 59.6034546 seconds, Stopping threads took: 59.6030773 seconds

Jednak zmień kod, aby używał metody natywnej, która zawsze ma bezpieczny punkt (jeśli nie jest wewnętrzna)

for (int i = 1; i != 0 ; i++) {
    boolean b = Math.cos(1.0 / i) == 0;
}

wydruki

Total time for which application threads were stopped: 0.0001444 seconds, Stopping threads took: 0.0000615 seconds

Uwaga: dodanie if (Thread.currentThread().isInterrupted()) { ... }do pętli dodaje bezpieczny punkt.

Uwaga: stało się to na 16-rdzeniowej maszynie, więc nie brakuje zasobów procesora.

Znalazłem odpowiedź, dlaczego . Nazywa się je bezpiecznymi punktami i są najlepiej znane jako Stop-The-World, który ma miejsce z powodu GC.

Zobacz te artykuły: Rejestrowanie przerw stop-the-world w JVM

Różne zdarzenia mogą spowodować, że maszyna JVM wstrzyma wszystkie wątki aplikacji. Takie przerwy nazywane są przerwami Stop-The-World (STW). Najczęstszą przyczyną wyzwalania pauzy STW jest wyrzucanie elementów bezużytecznych (na przykład w github), ale różne akcje JIT (przykład), odchylenie blokady (przykład), niektóre operacje JVMTI i wiele innych również wymagają zatrzymania aplikacji.

Punkty, w którym gwint aplikacyjne można bezpiecznie zahamować są nazywane, zaskoczenie, safepoints . Termin ten jest również często używany w odniesieniu do wszystkich przerw STW.

Rzadziej zdarza się, że dzienniki GC są włączone. Jednak nie przechwytuje to informacji o wszystkich punktach bezpieczeństwa. Aby uzyskać to wszystko, użyj tych opcji JVM:

-XX:+PrintGCApplicationStoppedTime -XX:+PrintGCApplicationConcurrentTime

Jeśli zastanawiasz się nad nazewnictwem wyraźnie odnoszącym się do GC, nie przejmuj się - włączenie tych opcji rejestruje wszystkie punkty bezpieczeństwa, a nie tylko przerwy w usuwaniu pamięci. Jeśli uruchomisz następujący przykład (źródło w github) z flagami określonymi powyżej.

Czytając Słowniczek terminów HotSpot , definiuje to:

bezpieczny punkt

Punkt podczas wykonywania programu, w którym znane są wszystkie korzenie GC i cała zawartość obiektu sterty jest spójna. Z globalnego punktu widzenia wszystkie wątki muszą blokować się w bezpiecznym punkcie, zanim GC będzie można uruchomić. (W szczególnym przypadku wątki z kodem JNI mogą nadal działać, ponieważ używają tylko uchwytów. Podczas punktu bezpiecznego muszą blokować zamiast ładować zawartość uchwytu). Z lokalnego punktu widzenia punkt bezpieczeństwa jest punktem wyróżniającym w bloku kodu, w którym wątek wykonawczy może blokować się dla GC.Większość stron telefonicznych kwalifikuje się jako punkty bezpieczeństwa.Istnieją silne niezmienniki, które są prawdziwe w każdym punkcie bezpieczeństwa, które można pominąć w punktach innych niż bezpieczne. Zarówno skompilowany kod Java, jak i kod C / C ++ są optymalizowane między punktami bezpieczeństwa, ale w mniejszym stopniu między punktami bezpieczeństwa. Kompilator JIT emituje mapę GC w każdym punkcie bezpieczeństwa. Kod C / C ++ na maszynie wirtualnej używa stylizowanych konwencji opartych na makrach (np. TRAPS) do oznaczania potencjalnych punktów bezpieczeństwa.

Działając z wyżej wymienionymi flagami, otrzymuję taki wynik:

Application time: 0.9668750 seconds
Total time for which application threads were stopped: 0.0000747 seconds, Stopping threads took: 0.0000291 seconds
timeElapsed=1015
Application time: 1.0148568 seconds
Total time for which application threads were stopped: 0.0000556 seconds, Stopping threads took: 0.0000168 seconds
timeElapsed=1015
timeElapsed=1014
Application time: 2.0453971 seconds
Total time for which application threads were stopped: 10.7951187 seconds, Stopping threads took: 10.7950774 seconds
timeElapsed=11732
Application time: 1.0149263 seconds
Total time for which application threads were stopped: 0.0000644 seconds, Stopping threads took: 0.0000368 seconds
timeElapsed=1015

Zwróć uwagę na trzecie zdarzenie STW:
Całkowity czas zatrzymania: 10,7951187 sekund
Zatrzymywanie wątków trwało: 10,7950774 sekund

Sam JIT praktycznie nie zajmował czasu, ale gdy JVM zdecydował się wykonać kompilację JIT, przeszedł w tryb STW, jednak ponieważ kod do kompilacji (nieskończona pętla) nie ma miejsca wywołania , nigdy nie osiągnięto punktu bezpiecznego.

STW kończy się, gdy JIT ostatecznie rezygnuje z czekania i stwierdza, że ​​kod jest w nieskończonej pętli.

Po prześledzeniu wątków komentarzy i kilku testach we własnym zakresie uważam, że pauza jest spowodowana przez kompilator JIT. Dlaczego kompilator JIT trwa tak długo, wykracza poza moje możliwości debugowania.

Ponieważ jednak zapytałeś tylko, jak temu zapobiec, mam rozwiązanie:

Przeciągnij nieskończoną pętlę do metody, w której można ją wykluczyć z kompilatora JIT

public class TestBlockingThread {
    private static final Logger LOGGER = Logger.getLogger(TestBlockingThread.class.getName());

    public static final void main(String[] args) throws InterruptedException     {
        Runnable task = () -> {
            infLoop();
        };
        new Thread(new LogTimer()).start();
        Thread.sleep(2000);
        new Thread(task).start();
    }

    private static void infLoop()
    {
        int i = 0;
        while (true) {
            i++;
            if (i != 0) {
                boolean b = 1 % i == 0;
            }
        }
    }

Uruchom swój program z tym argumentem VM:

-XX: CompileCommand = exclude, PACKAGE.TestBlockingThread :: infLoop (zamień PACKAGE na informacje o swoim pakiecie)

Powinieneś otrzymać taki komunikat, aby wskazać, kiedy metoda została skompilowana w JIT:
### Z wyłączeniem compile: static blocking.TestBlockingThread :: infLoop
Możesz zauważyć, że umieściłem klasę w pakiecie o nazwie blocking