Table of Contents

Laborator 07 - Profiling & Debugging

Nice to Watch

Latency Comparison Numbers

Operation Time (ns) Notes
L1 cache reference 0.5 ns
Branch mispredict 5 ns
L2 cache reference 7 ns 14x L1 cache
Mutex lock/unlock 25 ns
Main memory reference 100 ns20x L2 cache, 200x L1 cache
Compress 1K bytes with Zippy 3,000 ns
Send 1K bytes over 1 Gbps network 10,000 ns 0.01 ms
Read 4K randomly from SSD* 150,000 ns 0.15 ms
Read 1 MB sequentially from memory 250,000 ns 0.25 ms
Round trip within same datacenter 500,000 ns 0.5 ms
Read 1 MB sequentially from SSD* 1,000,000 ns 1 ms, 4x memory
Disk seek 10,000,000 ns 10 ms, 20x datacenter roundtrip
Read 1 MB sequentially from disk 20,000,000 ns 20 ms, 80x memory, 20x SSD
Send packet Caracal - NY - Caracal 150,000,000 ns 150 ms

Credits:

Linux

Profiler și tehnici de profiling

Un profiler este un utilitar de analiză a performanței care ajută programatorul să determine punctele critice – bottleneck – ale unui program. Acest lucru se realizează prin investigarea comportamentului programului, evaluarea consumului de memorie și relația dintre modulele acestuia.

Suportul pentru profilere este disponibil la nivel de:

Două moduri prin care se realizează profiling-ul sunt prezentate în continuare:

Tehnica de instrumentare (instrumentation)

Profiler-ele bazate pe această tehnică necesită de obicei modificări în codul programului: se inserează secțiuni de cod la începutul și sfârșitul funcției ce se dorește analizată. De asemenea, se rețin și funcțiile apelate. Astfel, se poate estima timpul total al apelului în sine cât și al apelurilor de subfuncții. Dezavantajul major al acestor profilere este legat de modificarea codului: în funcții de dimensiune scăzută și des apelate, acest overhead poate duce la o interpretare greșită a rezultatelor.

Tehnica de eșantionare (sampling)

Profiler-ele bazate pe sampling nu fac schimbări în codul programului, ci verifică periodic procesorul cu scopul de a determina ce funcție (instrucțiune) se execută la momentul respectiv. Apoi estimează frecvența și timpul de execuție al unei anumite funcții într-o perioadă de timp.

Unelte de profiling

În continuare sunt prezentate câteva unelte folosite în profiling.

perfcounters

Majoritatea procesoarelor moderne oferă registre speciale (performance counters) care contorizează diferite tipuri de evenimente hardware: instrucțiuni executate, cache-miss-uri, instrucțiuni de salt anticipate greșit, fără să afecteze performanța nucleului sau a aplicațiilor. Aceste registre pot declanșa întreruperi atunci când se acumulează un anumit număr de evenimente și astfel se pot folosi pentru analiza codului care rulează pe procesorul în cauză.

Subsistemul perfcounters:

perf

Utilitarul perf este interfața subsistemului perfcounters cu utilizatorul. Oferă o linie de comandă asemănătoare cu git și nu necesită existența unui daemon.

Un tutorial despre perf găsiți aici.

Utilizare perf

$ perf [--version] [--help] COMMAND [ARGS]

Cele mai folosite comenzi sunt:

perf list

Afișează numele simbolice ale tuturor tipurilor de evenimente ce pot fi urmărite de perf.

$ perf list 
List of pre-defined events (to be used in -e):
 
  cpu-cycles OR cycles                       [Hardware event]
  instructions                               [Hardware event]
 
  cpu-clock                                  [Software event]
  page-faults OR faults                      [Software event]
 
  L1-dcache-loads                            [Hardware cache event]
  L1-dcache-load-misses                      [Hardware cache event]
 
  rNNN                                       [Raw hardware event descriptor]
 
  mem:<addr>[:access]                        [Hardware breakpoint]
 
  syscalls:sys_enter_accept                  [Tracepoint event]
  syscalls:sys_exit_accept                   [Tracepoint event]

Atunci când un eveniment nu este disponibil în forma simbolică, poate fi folosit cu perf în forma procesorului din sistemul analizat.

perf stat

Rulează o comandă și afișează statisticile înregistrate de subsistemul performance counters.

$ perf stat ls -R /usr/src/linux
 Performance counter stats for 'ls -R /usr/src/linux':
 
         934.512846  task-clock-msecs         #      0.114 CPUs 
               1695  context-switches         #      0.002 M/sec
                163  CPU-migrations           #      0.000 M/sec
                306  page-faults              #      0.000 M/sec
          725144010  cycles                   #    775.959 M/sec 
          419392509  instructions             #      0.578 IPC   
           80242637  branches                 #     85.866 M/sec 
            5680112  branch-misses            #      7.079 %     
          174667968  cache-references         #    186.908 M/sec 
            4178882  cache-misses             #      4.472 M/sec 
 
        8.199187316  seconds time elapsed

perf stat oferă posibilitatea colectării datelor în urma rulării de mai multe ori a unui program specificând opțiunea -r.

$ perf stat -r 6 sleep 1
 Performance counter stats for 'sleep 1' (6 runs):
 
           1.757147  task-clock-msecs #      0.002 CPUs    ( +-   3.000% )
                  1  context-switches #      0.001 M/sec   ( +-  14.286% )
                  0  CPU-migrations   #      0.000 M/sec   ( +- 100.000% )
                144  page-faults      #      0.082 M/sec   ( +-   0.147% )
            1373254  cycles           #    781.525 M/sec   ( +-   2.856% )
             588831  instructions     #      0.429 IPC     ( +-   0.667% )
             106846  branches         #     60.806 M/sec   ( +-   0.324% )
              11312  branch-misses    #     10.587 %       ( +-   0.851% )
        1.002619407  seconds time elapsed   ( +-   0.012% )

Observați mai sus evenimentele cele mai importante contorizate.

perf top

Generează și afișează informații în timp real despre încărcarea unui sistem.

$ ls -R /home
$ perf top -p $(pidof ls)
--------------------------------------------------------------
   PerfTop:     181 irqs/sec  kernel:72.4% (target_pid: 10421)
--------------------------------------------------------------
             samples  pcnt function             DSO
             _______ _____ ____________________ ___________________
 
              270.00 15.8% __d_lookup           [kernel.kallsyms]  
              145.00  8.5% __GI___strcoll_l     /lib/libc-2.12.1.so
               99.00  5.8% link_path_walk       [kernel.kallsyms]  
               97.00  5.7% find_inode_fast      [kernel.kallsyms]  
               91.00  5.3% __GI_strncmp         /lib/libc-2.12.1.so
               55.00  3.2% move_freepages_block [kernel.kallsyms]  
               44.00  2.6% ext3_dx_find_entry   [kernel.kallsyms]  
               41.00  2.4% ext3_find_entry      [kernel.kallsyms]  
               40.00  2.3% dput                 [kernel.kallsyms]  
               39.00  2.3% ext3_check_dir_entry [kernel.kallsyms]  

Observăm că funcțiile de lucru cu fișiere (parcurgere, căutare) sunt cele care apar cel mai des în outputul lui perf-top corespunzător rulării comenzii de listare recursivă a directorului home.

perf record

Rulează o comandă și salvează informațiile de profiling în fișierul perf.data.

$ perf record wget http://elf.cs.pub.ro/so/wiki/laboratoare/laborator-07
 
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.008 MB perf.data (~334 samples) ]
 
$ ls
laborator-07  perf.data

perf report

Interpretează datele salvate în perf.data în urma analizei folosind perf record. Astfel pentru exemplul wget de mai sus avem:

$ perf report 
# Events: 13  cycles
#
# Overhead  Command      Shared Object  Symbol
# ........  .......  .................  ......
#
    86.43%     wget             e8ee21  [.] 0x00000000e8ee21
    11.03%     wget  [kernel.kallsyms]  [k] prep_new_page
     2.37%     wget  [kernel.kallsyms]  [k] sock_aio_read
     0.11%     wget  [kernel.kallsyms]  [k] perf_event_comm
     0.05%     wget  [kernel.kallsyms]  [k] native_write_msr_safe

Unelte de debugging

strace

strace interceptează şi înregistrează apelurile de sistem făcute de un proces şi semnalele pe care acesta le primeşte. În cea mai simplă formă strace rulează comanda specificată până când procesul asociat se încheie.

$strace cat /proc/cpuinfo
execve("/bin/cat", ["cat", "/proc/cpuinfo"], [/* 30 vars */]) = 0
open("/proc/cpuinfo", O_RDONLY)         = 3
read(3, "processor\t: 0\nvendor_id\t: Genuin"..., 32768) = 3652
write(1, "processor\t: 0$\nvendor_id\t: Genui"..., 7512) = 7512

Cele mai folosite opțiuni pentru strace sunt:

Un alt utilitar înrudit cu strace este ltrace. Acesta urmăreşte apelurile de bibliotecă.

gdb

Scopul unui debugger (de exemplu GDB, prin comanda gdb) este să ne permită să inspectăm ce se întâmplă în interiorul unui program în timp ce acesta rulează sau la terminarea execuției acestuia, în momentul când s-a produs o eroare fatală, pe baza fișierului coredump creat de către acesta.

Mai multe detalii în secțiunea de resurse.

valgrind

Valgrind reprezintă o suită de utilitare folosite pentru debugging și profiling. Printre cele mai folosite tool-uri sau unelte din această suită sunt:

Mai multe detalii aici.

Alte utilitare

Exerciții

În cadrul laboratoarelor vom folosi repository-ul de git al materiei SO - https://github.com/systems-cs-pub-ro/so. Va trebui sa clonați repository-ul pe masinile virtuale folosind comanda: git clone https://github.com/systems-cs-pub-ro/so. Dacă doriți să descărcați repositoryul în altă locație, folosiți comanda git clone https://github.com/systems-cs-pub-ro/so ${target}.

Pentru a actualiza repository-ul, folosiți comanda git pull origin master din interiorul directorului în care se află repository-ul. Recomandarea este să îl actualizați cât mai frecvent, înainte să începeți lucrul, pentru a vă asigura că aveți versiunea cea mai recentă. În cazul în care gitul detectează conflicte la nivelul vreunui fişier, folosiți următoarele comenzi pentru a vă păstra modificările:

git stash
git pull origin master
git stash pop

Pentru mai multe informații despre folosirea utilitarului git, urmați ghidul de la https://gitimmersion.com.

Linux

Întrucât avem nevoie de suport hardware, suport inexistent pe mașina virtuală, lucrați pe sistemul fizic.

Pentru a vedea ce pachet trebuie să instalați, rulați comanda perf fără parametri.

Pentru a putea face exercițiile e nevoie de pachetul linux-tools. Puteți verifica asta rulând comanda perf --help. Dacă utilitarul perf nu este găsit, trebuie să instalați pachetul folosind comenzile:

student@so:~$ sudo apt-get update
student@so:~$ sudo apt-get install linux-tools-generic

Exercițiul 1 - Custom Profiling

Scopul exercițiului este să analizăm numărul de instrucțiuni executate de către procesor pe baza unui executabil. Perf pune la dispoziție un mod de a extrage datele importante din profiling prin suportul de scripting oferit de perf script. Acesta funcționează împreună cu perf record care obține lista de sample-uri și o salvează în fișierul perf.data.

Intrați în directorul 1-custom. Primul pas este să generăm fișierul perf.data care conține sampleurile. Pentru asta executați :

make
sudo perf record -e cycles:pp -c 10000 -d ./hash

Folosiți comanda perf script cu opțiunea -F (investigați man perf-script) astfel încât să gasiți numărul total de valori ale instruction pointer-ului și apoi pe cele aflate în funcția hash_search_index. Având cele două valori, calculați procentul valorilor din funcția hash_search_index.

Folosiți wc -l pentru a număra liniile outputului și grep pentru a filtra după simbolul hash_search_index. Pentru a face calcule cu numere raționale folosiți o comandă de tipul: echo 7/2 | bc -l.

Opțional, puteți folosi script-ul pus la dispoziție în cadrul laboratorului pentru a calcula numărul de accese în cadrul funcției hash_search_index. Cu ajutorul lui perf script se pot parsa eventurile înregistrate în sample-uri în metoda process_event. Mai multe informații despre perf script se pot găsi la: man perf-script-python și exemplu de utilizare

Verificați rezultatul utilizând comanda perf report.

Exercițiul 2 - Row/Column major order

Folosind utilitarul perf_3.2 dorim să determinăm dacă limbajul C este column-major sau row-major (row-major-order).

Intrați în directorul 2-major și completați programul row.c astfel încât să incrementeze elementele unei matrice pe linii, după care completați programul columns.c astfel încât să incrementeze elementele unei matrice pe coloane.

Determinați numărul de cache-miss-uri comparativ cu numărul de accese la cache folosind perf stat pentru a urmări evenimentul L1-dcache-load-misses. Pentru a vedea evenimentele disponibile folosiți comanda perf list. Folosiți opțiunea -e a utilitarului perf pentru a specifica un anumit eveniment de urmărit (revedeți secțiunea perfcounters).

Exercițiul 3 - Busy

Intrați în directorul 3-busy și inspectați fișierul busy.c. Rulați programul busy și analizați încărcarea sistemului folosind comanda sudo perf top. Ce funcție pare să încarce sistemul?

Exercițiul 4 - Căutare într-un șir de caractere

Intrați în directorul 4-find-char/ și analizați conținutul fișierului find-char.c. Compilați fișierul find-char.c și rulați executabilul obținut.

Identificați, folosind perf record și perf report, care este funcția care ocupă cel mai mult timp de procesor și încercați să îmbunătățiți performanțele programului.

Exercițiul 5 - Printing order

Intrați în directorul 5-print/ și analizați conținutul fișierului print.c. Folosiți comanda make print pentru a compila programul print. Există fișierul Makefile?

Care este ordinea în care se fac scrierile la consolă? Explicați output-ul.

Puneți o instrucțiune sleep(5) înainte de return 0; în funcția main și folosiți comanda strace -e write ./print pentru a găsi explicația.

Exercițiul 6 - Flowers reloaded

Intrați în directorul 6-flowers/ și analizați conținutul fișierului flowers.c. Compilați fișierul flowers.c şi rulați executabilul flowers. Ce se întâmplă? Folosiți valgrind cu opțiunea --tool=memcheck. Afișați valoarea celui de-al treilea element al array-ului flowers, adică flowers[2].

Exercițiul 7 - Buffer overflow exploit

Rezolvați acest exercițiu pe mașina virtuală.

Intrați în directorul 7-exploit/ și analizați conținutul fișierului exploit.c. Folosiți comanda make pentru a compila executabilul exploit. Identificați o problemă în funcția read_name.

Folosiți gdb pentru a investiga stiva înaintea efectuării apelului read.

student@spook:~ gdb ./exploit
(gdb) break read_name
(gdb) run

Afișați adresele variabilelor name și access.

(gdb) print/x &access
(gdb) print/x &name

Observați că diferența între adresa variabilei access și adresa bufferului name este de 0x10 (16) octeți, ceea ce înseamnă că variabila access se află imediat la sfârșitul datelor din bufferul name.

Este posibil ca diferența dintre access și name să difere în funcție de arhitectura pe care lucrați. Calculați diferența dintre cele două adrese folosind valorile printate de gdb

Folosindu-vă de informațiile obținute, construiți un input convenabil pe care să îl oferiți executabilului exploit, astfel încât acesta să vă afișeze stringul “Good job, you hacked me!”.

Pentru a genera caractere neprintabile, puteți folosi interpretorul Python: python -c.

student@spook:~ python -c 'print "A"*8 + "\x01\x00\x00\x00"' | ./exploit

Comanda de mai sus va genera 8 octeți cu valoarea 'A' (codul ASCII 0x41), un octet cu valoarea 0x01 și încă 3 octeți cu valoarea 0x00 și îi va oferi la stdin executabilului exploit. Rețineti că datele sunt structurate în memorie în format little endian, prin urmare, dacă ultimii 4 octeți vor ajunge să suprascrie o adresă, aceasta va fi interpretată ca 0x00000001, NU 0x01000000.

Exercițiul 8 - Trace the mystery

Intrați în directorul 8-mystery/ unde găsiți executabilul mystery. Investigați și explicați ce face acesta. Revedeți secțiunea strace.

Resurse utile