Diagnozowanie wysokiego zużycia procesora w Docker na Mac

Jak zdiagnozować przyczynę Dockera w systemie MacOS, szczególnie com.docker.hyperkitprzy użyciu 100% procesora?

Statystyki dokerów

Statystyki Dockera pokazują, że wszystkie działające kontenery mają niski procesor, pamięć, netto IO i blok IO.

iosnoop

iosnoop pokazuje, że com.docker.hyperkitwykonuje do pliku około 50 zapisów na sekundę, w sumie 500 KB na sekundę Docker.qcow2. Według Co to jest Docker.qcow2? , Docker.qcow2to rzadki plik, który jest trwałym miejscem do przechowywania wszystkich kontenerów Docker.

W moim przypadku plik nie jest tak rzadki. Rozmiar fizyczny odpowiada rozmiarowi logicznemu.

dtrace (dtruss)

dtruss sudo dtruss -p $DOCKER_PIDpokazuje dużą liczbę połączeń psynch_cvsignali psynch_cvwait.

psynch_cvsignal(0x7F9946002408, 0x4EA701004EA70200, 0x4EA70100)          = 257 0
psynch_mutexdrop(0x7F9946002318, 0x5554700, 0x5554700)           = 0 0
psynch_mutexwait(0x7F9946002318, 0x5554702, 0x5554600)           = 89474819 0
psynch_cvsignal(0x10BF7B470, 0x4C8095004C809600, 0x4C809300)             = 257 0
psynch_cvwait(0x10BF7B470, 0x4C8095014C809600, 0x4C809300)               = 0 0
psynch_cvwait(0x10BF7B470, 0x4C8096014C809700, 0x4C809600)               = -1 Err#316
psynch_cvsignal(0x7F9946002408, 0x4EA702004EA70300, 0x4EA70200)          = 257 0
psynch_cvwait(0x7F9946002408, 0x4EA702014EA70300, 0x4EA70200)            = 0 0
psynch_cvsignal(0x10BF7B470, 0x4C8097004C809800, 0x4C809600)             = 257 0
psynch_cvwait(0x10BF7B470, 0x4C8097014C809800, 0x4C809600)               = 0 0
psynch_cvwait(0x10BF7B470, 0x4C8098014C809900, 0x4C809800)               = -1 Err#316

Aktualizacja: topna hoście Docker

Od https://stackoverflow.com/a/58293240/30900 :

docker run -it --rm --pid host busybox top

Zużycie procesora na hoście osadzonym dokera wynosi ~ 3%. Zużycie procesora na moim MacBooku wyniosło ~ 100%. Zatem wbudowany host dokera nie powoduje gwałtownego wzrostu zużycia procesora.

Aktualizacja: uruchamianie skryptów dtrace najpopularniejszych śladów stosu

Stosuj ślady ze skryptów dtrace w odpowiedzi poniżej: https://stackoverflow.com/a/58293035/30900 .

Te ślady stosu jądra wyglądają niewinnie.

              AppleIntelLpssGspi`AppleIntelLpssGspi::regRead(unsigned int)+0x1f
              AppleIntelLpssGspi`AppleIntelLpssGspi::transferMmioDuplexMulti(void*, void*, unsigned long long, unsigned int)+0x91
              AppleIntelLpssSpiController`AppleIntelLpssSpiController::transferDataMmioDuplexMulti(void*, void*, unsigned int, unsigned int)+0xb2
              AppleIntelLpssSpiController`AppleIntelLpssSpiController::_transferDataSubr(AppleInfoLpssSpiControllerTransferDataRequest*)+0x5bc
              AppleIntelLpssSpiController`AppleIntelLpssSpiController::_transferData(AppleInfoLpssSpiControllerTransferDataRequest*)+0x24f
              kernel`IOCommandGate::runAction(int (*)(OSObject*, void*, void*, void*, void*), void*, void*, void*, void*)+0x138
              AppleIntelLpssSpiController`AppleIntelLpssSpiDevice::transferData(IOMemoryDescriptor*, void*, unsigned long long, unsigned long long, IOMemoryDescriptor*, void*, unsigned long long, unsigned long long, unsigned int, AppleIntelSPICompletion*)+0x151
              AppleHSSPISupport`AppleHSSPIController::transferData(IOMemoryDescriptor*, void*, unsigned long long, unsigned long long, IOMemoryDescriptor*, void*, unsigned long long, unsigned long long, unsigned int, AppleIntelSPICompletion*)+0xcc
              AppleHSSPISupport`AppleHSSPIController::doSPITransfer(bool, AppleHSSPITransferRetryReason*)+0x97
              AppleHSSPISupport`AppleHSSPIController::InterruptOccurred(IOInterruptEventSource*, int)+0xf8
              kernel`IOInterruptEventSource::checkForWork()+0x13c
              kernel`IOWorkLoop::runEventSources()+0x1e2
              kernel`IOWorkLoop::threadMain()+0x2c
              kernel`call_continuation+0x2e
               53

              kernel`waitq_wakeup64_thread+0xa7
              pthread`__psynch_cvsignal+0x495
              pthread`_psynch_cvsignal+0x28
              kernel`psynch_cvsignal+0x38
              kernel`unix_syscall64+0x27d
              kernel`hndl_unix_scall64+0x16
               60

              kernel`hndl_mdep_scall64+0x4
              113

              kernel`ml_set_interrupts_enabled+0x19
              524

              kernel`ml_set_interrupts_enabled+0x19
              kernel`hndl_mdep_scall64+0x10
             5890

              kernel`machine_idle+0x2f8
              kernel`call_continuation+0x2e
            43395

Najczęstsze ślady stosu w przestrzeni użytkownika w ciągu 17 sekund wyraźnie wskazują na com.docker.hyperkit. Istnieje 1365 śladów stosu w 17 sekund, w których com.docker.hyperkitutworzono wątki, które średnio osiągają 80 wątków na sekundę.

              com.docker.hyperkit`0x000000010cbd20db+0x19f9
              com.docker.hyperkit`0x000000010cbdb98c+0x157
              com.docker.hyperkit`0x000000010cbf6c2d+0x4bd
              libsystem_pthread.dylib`_pthread_body+0x7e
              libsystem_pthread.dylib`_pthread_start+0x42
              libsystem_pthread.dylib`thread_start+0xd
               19

              Hypervisor`hv_vmx_vcpu_read_vmcs+0x1
              com.docker.hyperkit`0x000000010cbd4c4f+0x2a
              com.docker.hyperkit`0x000000010cbd20db+0x174a
              com.docker.hyperkit`0x000000010cbdb98c+0x157
              com.docker.hyperkit`0x000000010cbf6c2d+0x4bd
              libsystem_pthread.dylib`_pthread_body+0x7e
              libsystem_pthread.dylib`_pthread_start+0x42
              libsystem_pthread.dylib`thread_start+0xd
               22

              Hypervisor`hv_vmx_vcpu_read_vmcs
              com.docker.hyperkit`0x000000010cbdb98c+0x157
              com.docker.hyperkit`0x000000010cbf6c2d+0x4bd
              libsystem_pthread.dylib`_pthread_body+0x7e
              libsystem_pthread.dylib`_pthread_start+0x42
              libsystem_pthread.dylib`thread_start+0xd
               34

              com.docker.hyperkit`0x000000010cbd878d+0x36
              com.docker.hyperkit`0x000000010cbd20db+0x42f
              com.docker.hyperkit`0x000000010cbdb98c+0x157
              com.docker.hyperkit`0x000000010cbf6c2d+0x4bd
              libsystem_pthread.dylib`_pthread_body+0x7e
              libsystem_pthread.dylib`_pthread_start+0x42
              libsystem_pthread.dylib`thread_start+0xd
               47

              Hypervisor`hv_vcpu_run+0xd
              com.docker.hyperkit`0x000000010cbd20db+0x6b6
              com.docker.hyperkit`0x000000010cbdb98c+0x157
              com.docker.hyperkit`0x000000010cbf6c2d+0x4bd
              libsystem_pthread.dylib`_pthread_body+0x7e
              libsystem_pthread.dylib`_pthread_start+0x42
              libsystem_pthread.dylib`thread_start+0xd
              135

Powiązane sprawy

Github - docker / for-mac: com.docker.hyperkit 100% użycie procesora powróciło # 3499 . Jeden komentarz sugeruje dodanie buforowania woluminów opisanego tutaj: https://www.docker.com/blog/user-guided-caching-in-docker-for-mac/ . Próbowałem tego i uzyskałem niewielkie ~ 10% zmniejszenie zużycia procesora.

Mam ten sam problem. Mój procesor% wrócił do normy po usunięciu wszystkich woluminów.

docker system prune --volumes

Usunąłem również ręcznie niektóre nazwane woluminy:

docker volume rm NameOfVolumeHere

To nie rozwiązuje ogólnego problemu braku możliwości używania woluminów w Docker na Mac. W tej chwili zwracam uwagę na ilość używanych woluminów i zamykam pulpit Dockera, gdy nie jest używany.

Podejrzewam, że problem dotyczy IO. W przypadku woluminów MacOS obejmuje to osxfs, w których można dostrajać wydajność. Głównie, jeśli możesz zaakceptować mniej kontroli spójności, możesz ustawić tryb głośności na delegateddla szybszej wydajności. Więcej informacji można znaleźć w dokumentacji: https://docs.docker.com/docker-for-mac/osxfs-caching/ . Jeśli jednak obraz zawiera dużą liczbę małych plików, wydajność spadnie, zwłaszcza jeśli masz również wiele warstw obrazu.

Możesz także wypróbować następujące polecenie, aby debugować wszelkie problemy związane z procesem we wbudowanej maszynie wirtualnej używanej przez dokera:

docker run -it --rm --pid host busybox top

(Aby wyjść, użyj <ctrl>-c)

Aby wyśledzić, czy jest to IO, możesz także spróbować wykonać następujące czynności:

$ docker run -it --rm --pid host alpine /bin/sh
$ apk add sysstat
$ pidstat -d 5 12

To będzie działać w alpejskim kontenerze działającym w przestrzeni nazw pid VM, pokazując każde IO występujące w dowolnym procesie, niezależnie od tego, czy ten proces znajduje się w kontenerze. Statystyki są co 5 sekund przez jedną minutę (12 razy), a następnie daje średnią tabelę na proces. Możesz wtedy<ctrl>-d zniszczyć alpejski pojemnik.

Na podstawie komentarzy i zmian statystyki te mogą się sprawdzić. 4-rdzeniowy MBP ma 8 wątków, więc pełne wykorzystanie procesora powinno wynosić 800%, jeśli MacOS zgłasza to samo, co inne systemy oparte na Uniksie. W VM znajduje się ponad 100% obciążenia pokazane w górnym poleceniu dla średniej z ostatniej minuty (chociaż mniej z średnich 5 i 15), co jest mniej więcej tym, co widzisz dla procesu hyperkit na hoście. Natychmiastowe użycie wynosi ponad 12% od góry, a nie 3%, ponieważ musisz dodać procent systemu i użytkowników. A liczby IO pokazane w pidstat z grubsza pokrywają się z tym, co widzisz na obrazie qcow2.

Jeśli sam silnik dokowania jest wstrząsający (np. Ponowne uruchamianie kontenerów lub uruchamianie wielu sprawdzeń kondycji), możesz to debugować, obserwując dane wyjściowe:

docker events

Jest to mały skrypt dTrace, którego używam, aby znaleźć miejsce, w którym jądro spędza swój czas (pochodzi z systemu Solaris i pochodzi z początków systemu Solaris 10):

#!/usr/sbin/dtrace -s

profile:::profile-1001hz
/arg0/
{
    @[ stack() ] = count();
}

Po prostu pobiera próbki śladów stosu jądra i liczy każdy napotkany w pliku @hot agregacji.

Uruchom jako root:

... # ./kernelhotspots.d > /tmp/kernel_hot_spots.txt

Niech działa przez przyzwoity czas, gdy masz problemy z procesorem, a następnie naciśnij, CTRL-Caby przerwać skrypt. Wyemituje wszystkie napotkane ślady stosu jądra, najczęściej ostatnie. Jeśli potrzebujesz więcej (lub mniej) stosu ramek od domyślnego za pomocą

    @[ stack( 15 ) ] = count();

Spowoduje to wyświetlenie ramki stosu o głębokości 15 połączeń.

Ostatnie ślady stosu będą tam, gdzie jądro spędza większość swojego czasu. To może, ale nie musi, mieć charakter informacyjny.

Ten skrypt zrobi to samo dla śledzenia stosu przestrzeni użytkownika:

#!/usr/sbin/dtrace -s

profile:::profile-1001hz
/arg1/
{
    @[ ustack() ] = count();
}

Uruchom to podobnie:

... # ./userspacehotspots.d > /tmp/userspace_hot_spots.txt

ustack() jest nieco wolniejszy - aby wyemitować rzeczywiste nazwy funkcji, dTrace musi wykonać znacznie więcej pracy, aby uzyskać je z przestrzeni adresowej odpowiednich procesów.

Wyłączanie ochrony integralności systemu może pomóc uzyskać lepsze ślady stosu.

Więcej informacji znajdziesz w Podstawach działania DTrace .