~~REVEAL~~ ====== Profilowanie programów i odpluskwianie pamięci ====== ==== ===== * **Profilowanie** dynamiczna analiza programu, która dokonuje pomiaru złożoności czasowej lub/i pamięciowej w czasie jego działania * **Debbuger pamięci** narzędzie do poszukiwania wycieków pamięci i innych błędów związanych z niedozwolonym dostępęm do dynamicznie przydzielanych obszarów pamięci (np. buffer overflow) ===== Profilowanie ===== * Pomaga zlokalizować funkcje lub fragmenty kodu na które należy zwrócić uwagę przy optymalizacji szybkości działania programu * Czy warto optymalizować? * Funkcje wołane tysiące razy * Funkcje najbardziej kosztowne obliczeniowo * Profilowanie pomaga też często wykrywać błędy i lokalizować wady konstrukcji programu (np. niespodziewane wywołania funkcji lub brak wywołań) ==== Techniki profilowania ==== * **instrumentacja**, wstrzykiwanie do kodu instrukcji monitorujących (np. logi, liczniki wywołań, itp.) * profilowanie **oparte na zdarzeniach** * **statystyczna**, próbkowanie rejestru [[wp>Program_counter|Program counter]] * **symulacja**, [[wp>instruction set simulator]] (ISS), uruchamianie programu w symulowanym środowisku wirtualnym ==== Instrumentacja ==== **Instrumentacja** polega na dodawaniu do kodu instrukcji służących do uzyskania informacji o wydajności aplikacji * liczniki instrukcji i innych zdarzeń (performance counters) * zastępowanie funkcji alokujących pamięć * opakowanie wywołań funkcji odpowiednimi mechanizmami zliczającymi i liczącycmi czas wykonania ==== ==== Instrumentacja pozwala na: * precyzyjne śledzenie wykonywanych instrukcji * pomiar czasu wywołań w czasie działania programu * debbugowanie i wyłapywanie sytuacji wyjątkowych * logging ==== ==== Lecz nic nie jest za darmo... * instrumentacja ma duży wpływ na wydajność programu profilowanego * plik wykonywalny jest o wiele większy * może zaburzać pomiar utrudniająć wykrycie usterki, tzw. [[wp>Heisenbug]] ==== Rodzaje instrumentacji ==== * Ręczna, dokonywana przez programistę (logi, assercje) * Automatyczna modyfikacja kodu (Parasoft Insure%%++%%) * Instrumentacja kodu pośredniego, dodawana do assembly lub po dessaemblacji * Z wykorzystaniem kompilatorów, symbole debuggera umieszczene w kodzie maszynowym, \\ np. ''gcc -pg'' dla gprof, Quantify * Binarna, dodawana do kodu maszynowego (ATOM) * Dynamiczna, dodawna w momencie uruchamiania, program działa pod nadzorem narzędzia profilującego (Valgrind, Pin, DynamicRIO), kod modyfikowany w czasie wykonywania (DynInst) ==== Event-based profile ==== * profilowanie oparte na przechwytywanych zdarzeniach, np. tworzenie obiektów, wywołanie metod, odpalenie wątków * zakładanie haków (hooks) * .NET dołącza agenta profilującego jako serwer COM do CLR (Profiling API) * środowisko uruchomieniowe dostarcza informacji do agenta o wywołaniach metod, utworzeniu obiektów, itd. * agent profilujący potrafi podmienić bytecode profilowanego programu w odpowiedni sposób ==== Matody statystyczne ==== * Próbkowanie rejestru procesora wskazującego pozycję programu ([[wp>Program_counter|Program counter]]) za pomocą przerwań systemu operacyjnego z pewną częstością. * Metoda w małym stopniu lub wcale nie ingeruje w kod i wykonanie programu * Mniej dokładny pomiar ale pozwala na śledzenie działania programu profilowanego niemal z pełną szybkością. * Wyniki są przybliżeniem statystycznym i obarczone są błedem pomiarowym * Rozdzielczość pomiaru (ziernistośc danych): zależy od częstości próbkowania. Szybko wykonujące się funkcje bedą niezauważalne ===== Sposoby raportowania ===== * **profil**: ogólne statystyki zaobserwowanych zdarzeń, \\ np. zliczenie wywołań poszczególnych instrukcji, wystarczające dla programów sekwencyjnych (jednowątkowych). Raport zazwyczaj zawiera zestawienie kodu z liczbą wywołań więc jego rozmiar jest liniowy względem liczby linii kodu. * **ślad** (trace), ciąg zaobserwowanych zdarzeń, uwzględnia zależności czasowe także dla programów równoległych. Rozmiar liniowy względem długości ścieżki kodu (instruction path length), z tego względu często niepraktyczny w zastosowaniach. ==== ==== * ciągły monitoring na maszynie wirtualnej * śledzenie ścieżek w dowolnym, wybranym momencie, * śledzenie na żywo zmian w wydajności * mechanizmy usypiania procesów asynchronicznych w celu dokładniejszego obejrzenia równoległych procesów ==== Wynik działania ==== * **płaski** (flat) - sumaryczne czasy wywołań poszczególnych instrukcji lub funkcji * **graf wywołań** (call graph) - uwzględniają kolejność wywołań i pozwalają oddzielić czas działania funkcji wywołującej od funkcji badanej i funkcji potomnych * zależny od wejścia (input sensitive), uzależnia wynik profilowania od rozmiaru i/lub wartości danych wejściowych, widoczne niejako dodatkowy wymiar do profili płaskich i grafów wywołań ==== Call graph ==== {{https://upload.wikimedia.org/wikipedia/commons/2/2f/A_Call_Graph_generated_by_pycallgraph.png|}} Źródło: [[https://en.wikipedia.org/wiki/Call_graph|wikipedia.org]] ==== ==== * relacje wywołań pomiędzy funkcjami programu * cykle oznaczają rekujencję * brak informacji o kontekście ===== Narzędzia do profilowania ===== * GNU gprof, Valgrind (Unix/Linux) * Visual Studio Profiler * NetBeans Profiler, Eclipse Profiler Plugin * inne : nprof, CLR Profiler, RotateRight Zoom, pin, JProfiler (commercial), TAU Performance System, slimtune (.Net), CMT%%++%% (Complexity Measures Tool), AQtime (.Net, Java, commercial), * [[https://www.jetbrains.com/profiler/|dotTrace]] * [[wp>List_of_performance_analysis_tools|List of performance analysis tools]] ===== gprof ===== * Analiza wydajności programów dla Unix/Linux skompilowanych w GCC * Połączenie instrumentacji z próbkowaniem * Instrumentacja w czasie kompilacji \\ ''gcc -pg source_files '' * Funkcja monitorujące ''mcount()'' umieszczana przed każdym wywołaniem funkcji * Próbkowanie tworzy histogram wywołań badając stan licznika programu (program counter) co 0.01 s * Płaski profil + graf wywołań ==== Użycie gprof ==== * Instrumentacja \\ ''gcc -pg program.c -o program'' * Uruchomienie programu generuje plik ''gmon.out'' * Analiza wyników \\ ''grpof program gmon.out'' * ''gprof2dot'' pozwala wizualizować graf wywołań ==== Przykład ==== void func2(void) { int i = 0; for(;i<0xffffff;i++); return; } void func1(void) { int i = 0; for(;i<0xfffffff;i++); func2(); return; } int main(void) { int i = 0; for(;i<0xfffffff;i++); func1(); for(i=0 ; i< 3 ; i++) func2(); return 0; } ==== Profil płaski ==== gprof a.out gmon.out Flat profile: Each sample counts as 0.01 seconds. % cumulative self self total time seconds seconds calls ms/call ms/call name 44.92 0.80 0.80 1 799.52 850.12 func1 44.92 1.60 0.80 main 11.37 1.80 0.20 4 50.60 50.60 func2 ==== Graf wywołań ==== granularity: each sample hit covers 2 byte(s) for 0.56% of 1.80 seconds index % time self children called name [1] 100.0 0.80 1.00 main [1] 0.80 0.05 1/1 func1 [2] 0.15 0.00 3/4 func2 [3] ----------------------------------------------- 0.80 0.05 1/1 main [1] [2] 47.2 0.80 0.05 1 func1 [2] 0.05 0.00 1/4 func2 [3] ----------------------------------------------- 0.05 0.00 1/4 func1 [2] 0.15 0.00 3/4 main [1] [3] 11.2 0.20 0.00 4 func2 [3] ----------------------------------------------- ==== ==== {{ zajecia:npr:wyklad:test_gprof.png }} Inny przykład (program make): {{http://linuxgazette.net/100/misc/vinayak/overall-profile.txt}} [[https://raw.githubusercontent.com/jrfonseca/gprof2dot/master/sample.png|sample.png]] ==== Ograniczenia ==== * próbkowanie rejestrów procesora daje statystyczne przybliżenie (obarczone jest błędem) * pomiar czasu dotyczy tylko funkcji programu, nie uwzględnia czasu wywołań systemowych * duże spowolnienie działania aplikacji (w granicach 30% - 260%) * tylko GCC i kilka innych kompilatorów * problemy z cyklami w grafie wywołań (gprof nie analizuje całego grafu) ===== Analiza pamięci (Memory debugging tools) ===== * Valgrind, KCacheGrind (Linux/Unix, Android) * Visual Leak Detector (Visual C%%++%%) * Eclipse Memory Analyzer (Java) * inne: IBM Rational Purify, Insure%%++%%, TotalView, Dmalloc, memwatch, YAMD, mpatrol * [[https://www.jetbrains.com/dotmemory/|dotMemory]] * [[wp>Memory_debugger|Lista debbugerów pamięci]] ===== Valgrind - brama do Valhalli ===== {{ http://valgrind.org/images/st-george-dragon.png?200}} * Początkowo debbuger pamięci, obecnie rozbudowany framework do instrumentacji binarnej * Linux/Unix, Android, GPL v2 * Maszyna wirtualna - program jest tłumaczony (dekompilowany) do neutralnej dla procesora formy pośredniej (Intermediate Representation (IR)). Następnie dokonywana jest instrumentacja i wynik zamieniany jest ponownie na kod wykonywalny. ==== Narzędzia valgrind ==== * **Memcheck** (domyślnie) - błedy związane z przydziałem pamięci wynamicznej * **Cachegrind** - cache profiler, wizualizacja KCacheGrind * **Callgrind** - cachegrind + graf wywołań, wizualizacja KCacheGrind * **Helgrind** i **DRD** - analiza wielowątkowa, wykrywanie np. wyścigów (race condition), zakleszczeń, ... * **Massif** - profiler sterty + massif-visualizer * **Sgcheck** - wykrywanie błędów pamięci nieuwzględnianych przez memcheck (tablice na stercie i globalne) * **BBV** - ekstrapolacja wydajności za pomocą symulacji * None - uruchomienie programu bez analizy ==== Uruchamianie ==== valgrind [opcje valgrind] program [opcje programu] Przykład: valgrind --tool=memcheck ls -l Nie wymaga dostępu do źródeł programu ale kompilacja z symbolami debbugowania pozwala powiązać wynik z kodem: gcc -g kod_programu ==== Memcheck ==== * Analiza pamięci dynamicznej * Instrumentacja przechwytuje (podmienia) wywołania funkcji alokujących i zwalniających pamięć pozwalając na badanie przekroczenia granic alokowanej pamięci * **validity** - dostępnośc pamięci i porawaność instrukcji, bity V, dla pamięci i CPU * **addresability** - adresowalność pamięci, wskaźniki do zaalokowanego obszaru pamięci, bity A dla bajtów pamięci, narzut ~25% wielkości programu * Dokładność: dostęp do pamięci na poziomie bajta, inzicjalizacje zmiennych na poziomie bita * Program wykonywany 20-30 razy wolniej, zajmuje o wiele więcej pamięci ==== Memcheck: wykrywane błędy ==== * Dostęp do niezaalokowanego obszaru pamięci * Przekroczenie granic zaalokowanej pamięci * Próba dostępu do pamięci po jej zwolnieniu * Wycieki pamięci * Wykorzystanie niezainicjowanych zmiennych * Błedy przy kopiowania buforów, np. memcpy ==== Przykład ==== #include void f(void) { int* x = malloc(10 * sizeof(int)); x[10] = 0; // problem 1: heap block overrun } // problem 2: memory leak -- x not freed int main(void) { f(); return 0; } ==== ==== gcc -pg -g mem1.c valgrind --leak-check=yes a.out ==23065== Invalid write of size 4 ==23065== at 0x400670: f (mem1.c:8) ==23065== by 0x400685: main (mem1.c:13) ==23065== Address 0x51fd778 is 0 bytes after a block of size 40 alloc'd ==23065== at 0x4C2AB80: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so) ==23065== by 0x400663: f (mem1.c:7) ==23065== by 0x400685: main (mem1.c:13) ==23065== ==23065== ==23065== HEAP SUMMARY: ==23065== in use at exit: 40 bytes in 1 blocks ==23065== total heap usage: 2 allocs, 1 frees, 1,780 bytes allocated ==23065== ==23065== 40 bytes in 1 blocks are definitely lost in loss record 1 of 1 ==23065== at 0x4C2AB80: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so) ==23065== by 0x400663: f (mem1.c:7) ==23065== by 0x400685: main (mem1.c:13) ==23065== ==== Wycieki pamięci ==== * Still reachable - pamięć jest osiągalna * Definitely lost - brakuje wskaźnika do zaalokowanej pamięci * Indirectly lost - istnieją wskaźniki do tej pamięci ale i tak nie ma tam dostępu, np. drzewo bez korzenia * Possibly lost - może być problem dla zarządzanego kodu (interior-pointers) ==23065== LEAK SUMMARY: ==23065== definitely lost: 40 bytes in 1 blocks ==23065== indirectly lost: 0 bytes in 0 blocks ==23065== possibly lost: 0 bytes in 0 blocks ==23065== still reachable: 0 bytes in 0 blocks ==23065== suppressed: 0 bytes in 0 blocks ==== Cachegrind i Callgrind ==== * **Cachegrind** symuluje szczegółowo cache I1, D1 i L2. Pozwala identyfikować poszczególne wywołania linii kodu i odwołania do pamięci. * Podsumowania wyników dla funkcji, modułów, całego programu * Działa dla programów napisanych w dowolnym języku * Około 20-100x woniej * **Callgrind** uzupełnia analizę Cachegrind o graf wywołań * [[http://kcachegrind.sourceforge.net/html/Home.html|KCachegrind]] - wizualizacja danych z cachegrind i callgrind ==== KCachegrind ==== valgrind --toll=callgrind program kcachegrind | {{ http://kcachegrind.sourceforge.net/html/pics/KcgShot3Large.gif?360 }} | {{ http://kcachegrind.sourceforge.net/html/pics/KcgShot4Large.png?360 }} | ===== Profilowanie kodu w VS2013 ===== * **Sampling** zbiera dane statystyczne dotyczące wykonywanej aplikacji próbkując obciążenie CPU i stan stosu * **Instrumentation** - pomiary wywołania poszczególnych funkcji * **Concurrency** aplikacje wielowątkowe * **.NET memory** użycie pamięci i //garbage collection// * **Tier interaction** zawołania ADO.NET do baz danych SQL Serwera ==== Performance Session ==== {{ :zajecia:znd_2014_1:profiler_explorer.png?300|}} **Perforamnce Explorer**: \\ konfiguracja sesji, \\ uruchamianie testów, \\ porównywanie raportów ==== ==== * **Performance Session** - konfiguracja analizy + raporty * **Targets** - cel analizy: projekt, działający proces, plik wykonywalny * **Reports** - pliki zawierające informacje zebrane podczas analizy * **Attach/Detach** - podłączenie profilowania do działającego procesu ==== Wymagania ==== * Uprawnienia administracyjne - wymagane przez metody próbkowania (sampling) oraz mające dostęp do wywołań systemowych * Skompilowanie aplikacji do wersji **Release** * Debug symbols files (.pdb) - m.in. definicja nazw funkcji systemowych * Visual Studio Professional/Premium/Ultimate * Windows 8, Windows Server 2012, aplikacje Windows Store - wymagają innych technik profilowania, nie wszystkie wymienione tu są wspierane w VS ==== Raport ==== {{ :zajecia:znd_2014_1:profiler_summary.png?800 |}} ==== ==== * **Hot Path** najaktywniejsza ścieżka drzewa wywołań funkcji * Lista funkcji wykonujących najwięcej pracy * ''Inclusive'' - łącznie dla całej funkcji, i * ''Exclusive'' - po odjęciu funkcji wołanych z wnętrza analizowanej funkcji ==== Sampling ==== * W stałych odstępach czasu pobiera z CPU stan stosu (informacje o autualnie wykonywanych funkcjach) * Próbkowanie: domyślnie co 10M cykli (0.01 s dla 1GHz), inne możliwe zdarzenia do próbkowania: * błędy stronicowania * wywołania systemowe * performance counters (CPU counters) * w czasie próbkowania zwiekszany jest licznik wywołań (inclusive samples) dla wszystkich funkcji ze stosu * Funkcja aktualnie wykonywana otrzymuje zwiększony licznik exclusive sample oraz inclusive sample * Inclusive samples - całkowita liczba próbek zebranych dla danej funnkcji * Exclusive samples - liczba próbek pobranych w czasie gdy funkcja była wykonywana ==== Instrumentation ==== * Pomiar czasu wykonania funkcji, linii kodu i poszczególnych instrukcji * Wstrzykiwany kod na początku i końcu badanych funkcji, mierzony jest czas pomiędzy kolejnymi zdarzeniami * Sprawdzane jest czy pomiędzy zdarzeniami system dokonywał innych operacji (np. odczyt z dysku, komunikacja miedzy wątkami, ...) * Dla każdego zarejestrowanego interwału odtwarzany jest stos wywołań w celu określenia funkcji potomnych ==== ==== * Elapsed Inclusive - czas wykoanania danej funkcji * Elapsed Exclisive - czas z pominięciem czasu funkcji potomnych * Application Inlcusive - czas wywołań w czasie których nie nastąpiło wywołanie systemowe * Application Exclusive - jak wyżej, z pominięciem czasów funkcji potomnych ==== Szczegóły analizy funkcji ==== {{ :zajecia:znd_2014_1:profiler_function_details.png?500 |}} ==== Error List ==== * Okno ''Error List'' zawiera ostrzeżenia i wskazówki dotyczące efektywności aplikacji * [[http://msdn.microsoft.com/en-us/library/ee843874.aspx|Performance Rules]]: błędy, ostrzeżenia, informacje {{ :zajecia:znd_2014_1:profiler_errors.png?800 |}} ==== Filtrowanie wyników ==== {{ http://i.msdn.microsoft.com/dynimg/IC359349.png }}\\ Żródło: http://msdn.microsoft.com ==== CPU and Windows Counters ==== * VS Profiler pozwala zbierać informacje o zdarzeniach systemu (windows counters, events) i procesora (CPU counters) * Windows counters - zdarzenia dostarczane przez infrastrukture diagnostyczną systemu, w zależności od konfiguracji nie muszą wystepować. Dostarczają informacji o wydajności OS, aplikacji, usług i sterowaników * CPU counters - zdarzenia związane ze sprzętem zliczane przez CPU * Portable Performance counter * Platform Events - specyficzne dla danej architektury, nie przenośne ==== Memory Allocation and Object Lifetime ==== * Zbiera informacje o rozmiarze i liczbie alokowanych obiektów i obiektów niszczoncyh w garbage collector * Zachowuje stan stosu dla każdego takiego zdarzenia * Inclusive Sample Count - liczba zdarzeń alokacji obiektu gdy funkcja znajdowała się na stosie * Exclusive Sample Count - liczba zdarzeń alokacji obiektu gdy funkcja była wywoływana (była na szczycie stosu) * Object Lifetime view - ilość i rozmiar zaalokowanych obiektów oraz informacja o generacji GC w której zostały //zniszczone// ==== Raport ==== {{zajecia:npr:vs_memory_profiler1.png?800}} ==== ==== * Całkowita zajęcośc pamięci * Funkcje, które zaalokowały najwięcej pamięci * Lista typów obiektów zajmujących najwięcej miejsca * Lista typów posiadających najwięcej instancji ==== Porównywanie raportów ==== {{ :zajecia:znd_2014_1:profiler_cmp.png?650 |}} ===== Podsumowanie ===== * Pozwala wskazać fragmenty kodu, które należy rozpatrzyć pod względem optymalizacji * Dynamiczna analiza: sprawdzane tylko te elementy które zostały wykoane * Profilowanie jest kosztowne czasowo i pamięciowo * Profilowanie jest obarczone błędami, każda technika ma swoje ograniczenia ===== Więcej informacji ===== * [[http://msdn.microsoft.com/en-us/library/ms182372.aspx|Beginners Guide to Performance Profiling]] * [[http://msdn.microsoft.com/en-us/library/z9z62c29.aspx|Analyzing Application Performance by Using Profiling Tools]] * [[http://msdn.microsoft.com/en-us/magazine/cc337887.aspx|Find Application Bottlenecks with Visual Studio Profiler]] by Hari Pulapaka and Boris Vidolov * [[wp>Profiling_%28computer_programming%29|Profilowanie - Profiling (computer programming)]] * [[http://en.wikipedia.org/wiki/List_of_performance_analysis_tools]] * [[http://linuxgazette.net/100/vinayak.html|Profiling programs using gprof]] by Vinayak Hegde (Linux Gazette) * [[http://valgrind.org/docs/manual/index.html|Valgrind Documentation]]