This is an old revision of the document!


Laboratorul 10 - Profiling & Debugging

Materiale ajutătoare

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 ns 20x 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

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:

  • bibliotecă C (GNU libc), prin informații legate de timpul de viață al alocărilor de memorie,
  • compilator, prin modificarea codului în tehnica de instrumentare se poate realiza ușor în procesul de compilare, compilatorul fiind cel ce inserează secțiunile de cod necesare,
  • nucleu al sistemului de operare, prin punerea la dispoziție de apeluri de sistem specifice,
  • hardware, unele procesoare sunt dotate cu contoare de temporizare ( Time Stamp Counter - TSC) sau contoare de performanță care numără evenimente precum cicluri de procesor sau TLB miss-uri.

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:

  • se găsește în nucleul Linux începând cu versiunea 2.6.31 (CONFIG_PERF_COUNTERS=y)
  • este înlocuitorul lui oprofile
  • oferă suport pentru:
    • evenimente hardware (instrucțiuni, accese cache, ciclii de magistrală).
    • evenimente software (page fault, cpu-clock, cpu migrations).
    • tracepoints (e.g: sys_enter_open, sys_exit_open).

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:

  • annotate - Citește perf.data și afișează codul cu adnotări
  • list - Listează numele simbolice ale tuturor tipurilor de evenimente ce pot fi urmărite de perf
  • lock - Analizează evenimentele de tip lock
  • record - Rulează o comandă și salvează informațiile de profiling în fișierul perf.data
  • report - Citește perf.data (creat de perf record) și afișează profilul
  • sched - Utilitar pentru măsurarea proprietăților planificatorului (latențe)
  • stat - Rulează o comandă și afișează statisticile înregistrate de subsistemul performance counters
  • top - Generează și afișează informații în timp real despre încărcarea unui sistem

perf list

man 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   

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

perf stat

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

man 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

man 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

man 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 debudding

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:

  • -f, cu această opțiune vor fi urmărite şi procesele copil create de procesul curent
  • -o filename, în mod implicit strace afişează informațiile la stderr. Cu această opțiune, output-ul va fi pus în fişierul filename
  • -p pid, pid-ul procesului de urmărit.
  • -e expresie, modifică apelurile urmărite.
iuliana@debian$ strace -f -e connect,socket,bind -p $(pidof iceweasel)
Process 6429 attached with 30 threads - interrupt to quit
socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 50
connect(50, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("141.85.227.65")}, 16) = -1 EINPROGRESS

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.

valgrind

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

  • memcheck - Realizează analiza utilizării memoriei
  • cachegrind - Realizează analiza performanței cache-ului
  • helgrind - Folosit pentru depanarea condițiilor de cursă în cadrul programelor cu multiple fire de execuție (multithreaded).

Alte utilitare

 Alte utilitare

sde/laboratoare/10.1555345741.txt.gz · Last modified: 2019/04/15 19:29 by iuliana.marin
CC Attribution-Share Alike 3.0 Unported
www.chimeric.de Valid CSS Driven by DokuWiki do yourself a favour and use a real browser - get firefox!! Recent changes RSS feed Valid XHTML 1.0