Dlaczego moja aplikacja Pythona utknęła w martwym punkcie czasu systemu/jądra

Question

Po pierwsze, nie byłem pewien, czy powinienem opublikować to pytanie jako Ubuntu, czy tutaj. Ale domyślam się, że to raczej pytanie Pythona niż OS.

Moja aplikacja Pythona działa na systemie Ubuntu na 64-rdzeniowym serwerze AMD. Ciągnie obrazy z kamer 5 GigE przez sieć, wywołując do .so przez ctypes, a następnie przetwarza je. Widzę częste przerwy w mojej aplikacji powodujące zrzucanie ramek z kamer przez bibliotekę zewnętrznych kamer.

Do debugowania użyłem popularnego pakietu Python psutil, z którego loguję statystyki procesora co 0,2 sekundy w osobnym wątku. Śpię przez 0,2 sekundy w tym wątku, a kiedy sen trwa znacznie dłużej, widzę także opuszczane ramki. Widziałem przerwy do 17 sekund! Większość mojego przetwarzania odbywa się w OpenCV lub Numpy (obie z nich uwalniają GIL) lub w jednej części aplikacji, a następnie 59 procesów (aby obejść GIL Pythona).

Moje rejestrowanie debugowania pokazuje bardzo wysoki "proces" (tj. Jądro) czas procesora na wielu wątkach mojego procesu, gdy występują przerwy.

Na przykład. Widzę czasy procesora w następujący sposób (zwykle co 0,2 sekundy), a następnie nagle duży skok (liczby procesowe są w wykorzystaniu procesora, tj. 1 w pełni wykorzystany procesor to 1, Linux top pokazujący 123% będzie 1,2):

Process user | Process system | OS system % | OS idle % 
19.9   | 10.5   | 6   | 74 
5.6   | 2.3   | 4   | 87 
6.8   | 1.7   | 11   | 75 
4.6   | 5.5   | 43   | 52 
0.5   | 26.4   | 4   | 90 

Nie wiem, dlaczego wysokie użycie systemu OS jest zgłaszane w jednej linii przed dopasowaniem wysokiego wykorzystania systemu procesowego. Oba pasują od 26,4 z 64 rdzeni = 41%. W tym momencie moja aplikacja doświadczyła około 3,5-sekundowej przerwy (określonej przez mój dziennik logowania informacji o procesorze przy użyciu OpenCV cv2.getTickCount() oraz skok znaczników czasu w logu Pythona) powodując upuszczenie wielu ramek kamery.

Kiedy to się dzieje, zalogowałem się również do informacji o procesorze dla każdego wątku mojego procesu. Dla powyższego przykładu 25 wątków pracowało przy "systemowym" obciążeniu procesora 0,9, a jeszcze więcej przy 0,6, co odpowiada sumie dla procesu 26.4 powyżej. W tym momencie uruchomiono około 183 wątków.

Ta przerwa zwykle wydaje się bliska po użyciu puli wieloprocesowej (jest używana w krótkich seriach), ale w żadnym wypadku nie dzieje się za każdym razem, gdy używana jest pula. Ponadto, jeśli zmniejszę o połowę liczbę operacji przetwarzania poza pulą, nie nastąpi pominięcie kamery.

Pytanie: jak mogę określić, dlaczego czas systemu operacyjnego/jądra systemu nagle przechodzi przez dach? Dlaczego tak się stanie w aplikacji Pythona?

Co ważniejsze: wszelkie pomysły, dlaczego tak się dzieje i jak tego uniknąć?

Uwagi:

• ten działa jako root (to musi dla biblioteki aparatu niestety) od upstart
• Gdy kamery są wyłączone ponownym uruchomieniu aplikacji (używając respawn w nowobogackich) i to się dzieje wielokrotność Zauważyłem też, że stało się to bardzo szybko po rozpoczęciu procesu.
• Ten sam kod jest uruchamiany w kółko, nie jest to spowodowane uruchomieniem innej gałęzi mojego kodu
• Obecnie ma nice od -2, próbowałem usunięcie nice bez wpłynąć
• Ubuntu 12.04.5 LTS
• Python 2.7
• Maszyna posiada 128GB pamięci, która nie jestem, gdzie niedaleko użyciu

Answer 1

OK. Mam odpowiedź na moje własne pytanie. Tak, zajęło mi to ponad 3 miesiące, aby dojść tak daleko.

Wygląda na to, że GIL wtrąca się w Pythonie, co jest przyczyną ogromnych "systemowych" skoków procesora i związanych z nimi przerw. Oto good explanation of where the thrashing comes from. Ta prezentacja wskazała mi również właściwy kierunek.

Python 3.2 introduced a new GIL implementation, aby uniknąć tego drażnienia. Wynik może być przedstawiony za pomocą prostego przykładu gwintowany (zaczerpnięte z prezentacji powyżej):

from threading import Thread 
import psutil 

def countdown(): 
    n = 100000000 
    while n > 0: 
     n -= 1 

t1 = Thread(target=countdown) 
t2 = Thread(target=countdown) 
t1.start(); t2.start() 
t1.join(); t2.join() 

print(psutil.Process().cpu_times())  

Na mój Macbook Pro z Python 2.7.9 to wykorzystuje 14.7s z CPU „user” i 13.2s z „systemu” PROCESOR.

Python 3.4 używa 15,0 s "użytkownika" (nieco więcej), ale tylko 0,2 s "systemu".

Tak więc GIL nadal działa, działa tylko tak szybko, jak w przypadku pojedynczego wątku, ale unika całej rywalizacji GIL o Pythonie 2, która manifestuje się jako czas procesora jądra ("system"). Ten spór, jak sądzę, jest przyczyną problemów pierwotnego pytania.

Aktualizacja

Dodatkową przyczyną problemu CPU okazała się być z OpenCV/TBB. W pełni udokumentowane w tym SO question.