→ Slide 1

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)
→ Slide 2
  • 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ń)
↓ Slide 3

Techniki profilowania

  • instrumentacja, wstrzykiwanie do kodu instrukcji monitorujących (np. logi, liczniki wywołań, itp.)
  • profilowanie oparte na zdarzeniach
  • statystyczna, próbkowanie rejestru Program counter
  • symulacja, instruction set simulator (ISS), uruchamianie programu w symulowanym środowisku wirtualnym
↓ Slide 4

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. Heisenbug
↓ Slide 5

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)
↓ Slide 6

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
↓ Slide 7

Matody statystyczne

  • Próbkowanie rejestru procesora wskazującego pozycję programu (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
→ Slide 8
  • 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
↓ Slide 9

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ń
↓ Slide 10

Call graph

Źródło: wikipedia.org

  • relacje wywołań pomiędzy funkcjami programu
  • cykle oznaczają rekujencję
  • brak informacji o kontekście
→ Slide 11
  • 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),
→ Slide 12
  • 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ń
↓ Slide 13

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ń
↓ Slide 14

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;
}
↓ Slide 15

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
↓ Slide 16

Graf wywołań

granularity: each sample hit covers 2 byte(s) for 0.56% of 1.80 seconds

index % time    self  children    called     name
                                                 <spontaneous>
[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]
-----------------------------------------------

Inny przykład (program make): overall-profile.txt sample.png

↓ Slide 17

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)
→ Slide 18
  • Valgrind, KCacheGrind (Linux/Unix, Android)
  • Visual Leak Detector (Visual C++)
  • Eclipse Memory Analyzer (Java)
  • inne: IBM Rational Purify, Insure++, TotalView, Dmalloc, memwatch, YAMD, mpatrol
→ Slide 19

  • 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.
↓ Slide 20

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
↓ Slide 21

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
↓ Slide 22

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
↓ Slide 23

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
↓ Slide 24

Przykład

#include <stdlib.h>
 
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== 
↓ Slide 25

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
↓ Slide 26

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ń
  • KCachegrind - wizualizacja danych z cachegrind i callgrind
↓ Slide 27

KCachegrind

valgrind --toll=callgrind program
kcachegrind
→ Slide 28
  • 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
↓ Slide 29

Performance Session

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
↓ Slide 30

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
↓ Slide 31

Raport

  • 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
↓ Slide 32

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
↓ Slide 33

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
↓ Slide 34

Szczegóły analizy funkcji

↓ Slide 35

Error List

  • Okno Error List zawiera ostrzeżenia i wskazówki dotyczące efektywności aplikacji
  • Performance Rules: błędy, ostrzeżenia, informacje

↓ Slide 36

Filtrowanie wyników


Żródło: http://msdn.microsoft.com

↓ Slide 37

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
↓ Slide 38

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
↓ Slide 39

Raport

  • 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
↓ Slide 40

Porównywanie raportów

→ Slide 41
  • 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
→ Slide 42