Felsökning och profilering

En gyllene regel inom programmering är att kod inte gör det du förväntar dig att den ska göra, utan det du säger åt den att göra. Att överbrygga den luckan kan ibland vara ganska svårt. I den här föreläsningen går vi igenom användbara tekniker för att hantera felaktig och resurshungrig kod: felsökning och profilering.

Felsökning (debugging)

Printf-felsökning och loggning

“The most effective debugging tool is still careful thought, coupled with judiciously placed print statements” — Brian Kernighan, Unix for Beginners.

Ett första sätt att felsöka ett program är att lägga till utskriftssatser kring där du upptäckt problemet, och fortsätta iterera tills du extraherat tillräcklig information för att förstå vad som orsakar felet.

Ett andra sätt är att använda loggning i ditt program, i stället för ad hoc-utskriftssatser. Loggning är i princip “utskrift med mer omsorg”, och görs vanligtvis med ett loggningsramverk som har inbyggt stöd för saker som:

Loggsatser lägger du också ofta in proaktivt medan du programmerar så att datan du behöver för att felsöka redan kan finnas där. Och när du väl hittat och rättat ett problem med utskriftssatser är det ofta värt att konvertera dessa utskrifter till riktiga loggsatser innan du tar bort dem. På så sätt har du redan den diagnostiska information du behöver om liknande programfel uppstår i framtiden, utan att behöva ändra koden.

Loggar från tredjepart: Många program stödjer flaggan -v eller --verbose för att skriva ut mer information när de körs. Det kan vara användbart för att upptäcka varför ett visst kommando misslyckas. Vissa tillåter till och med att flaggan upprepas för mer detaljer. När du felsöker problem med tjänster (databaser, webbservrar, etc.), kontrollera deras loggar, ofta i /var/log/ på Linux. Använd journalctl -u <service> för att visa loggar för systemd-tjänster. För tredjepartsbibliotek, kontrollera om de stödjer felsökningsloggning via miljövariabler eller konfiguration.

Felsökare

Printf-felsökning fungerar bra när du vet vad du ska skriva ut och enkelt kan modifiera och köra om koden. Felsökare blir värdefulla när du inte vet vilken information du behöver, när programfelet bara visar sig under svårreproducerade förhållanden, eller när det är dyrt att modifiera och starta om programmet (långa uppstartstider, komplext tillstånd att återskapa, etc.).

Felsökare är program som låter dig interagera med programmets körning medan den sker, och låter dig:

De flesta programmeringsspråk stödjer (eller kommer med) någon form av felsökare. De mest mångsidiga är allmänna felsökare som gdb (GNU Debugger) och lldb (LLVM Debugger), som kan felsöka vilken nativ binär som helst. Många språk har också språkspecifika felsökare som integrerar tätare med körmiljön (som Pythons pdb eller Javas jdb).

gdb är den faktiska standardfelsökaren för C, C++, Rust och andra kompilerade språk. Den låter dig undersöka i princip vilken process som helst och se dess aktuella maskintillstånd: register, stack, programräknare och mer.

Några användbara GDB-kommandon:

Överväg att använda GDB:s TUI-läge (gdb -tui eller tryck Ctrl-x a i GDB) för delad skärm med källkod bredvid kommandoprompten.

Inspelnings-/uppspelningsfelsökning

Några av de mest frustrerande programfelen är så kallade Heisenfel (Heisenbugs): programfel som verkar försvinna eller ändra beteende när du försöker observera dem. Race conditions, tidsberoende programfel och problem som bara dyker upp under vissa systemförhållanden tillhör den här kategorin. Traditionell felsökning är ofta värdelös här eftersom nästa körning ger annat beteende (t.ex. kan utskriftssatser sakta ner koden så mycket att racet inte längre händer).

Inspelnings-/uppspelningsfelsökning (record-replay) löser detta genom att spela in ett programs körning och låta dig spela upp den deterministiskt så många gånger du behöver. Ännu bättre är att du kan gå baklänges i körningen för att hitta exakt var något gick fel.

rr är ett kraftfullt verktyg för Linux som spelar in programkörning och tillåter deterministisk uppspelning med fulla felsökningsmöjligheter. Det fungerar med GDB, så du kan redan gränssnittet.

Grundläggande användning:

# Spela in en programkörning
rr record ./my_program

# Spela upp inspelningen (öppnar GDB)
rr replay

Magin sker under uppspelning. Eftersom körningen är deterministisk kan du använda kommandon för omvänd felsökning (reverse debugging):

Detta är otroligt kraftfullt för felsökning. Säg att du har en krasch, i stället för att gissa var programfelet är och sätta brytpunkter kan du:

  1. Köra till kraschen.
  2. Inspektera det korrupta tillståndet.
  3. Sätta en watchpoint på den korrupta variabeln.
  4. Köra reverse-continue för att hitta exakt var den blev korrupt.

När du ska använda rr:

Obs: rr fungerar bara på Linux och kräver hårdvaruprestandaräknare. Det fungerar inte i VM:ar som inte exponerar dessa räknare, till exempel på de flesta AWS EC2-instanser, och stödjer inte GPU-åtkomst. För macOS, kolla in Warpspeed.

rr och samtidighet: Eftersom rr spelar in körningen deterministiskt serialiserar det trådschemaläggning. Det innebär att vissa race conditions kanske inte visar sig under rr om de beror på specifik timing. rr är fortfarande användbart för att felsöka race-problem, när du väl fångat en felande körning kan du spela upp den tillförlitligt, men du kan behöva flera inspelningsförsök för att fånga ett intermittent programfel. För programfel utan samtidighet glänser rr mest: du kan alltid reproducera exakt körning och använda omvänd felsökning för att jaga ner korruption.

Spårning av systemanrop

Ibland behöver du förstå hur programmet interagerar med operativsystemet. Program gör systemanrop för att begära tjänster från kärnan, öppna filer, allokera minne, skapa processer och mer. Att spåra dessa anrop kan avslöja varför ett program hänger sig, vilka filer det försöker komma åt eller var det spenderar tid på att vänta.

strace (Linux) och dtruss (macOS)

strace låter dig observera varje systemanrop ett program gör:

# Spåra alla systemanrop
strace ./my_program

# Spåra bara filrelaterade anrop
strace -e trace=file ./my_program

# Följ barnprocesser (viktigt för program som startar andra program)
strace -f ./my_program

# Spåra en redan körande process
strace -p <PID>

# Visa tidsinformation
strace -T ./my_program

På macOS och BSD, använd dtruss (som kapslar dtrace) för liknande funktionalitet.

För djupdykningar i strace, kolla Julia Evans utmärkta strace-zine.

bpftrace och eBPF

eBPF (extended Berkeley Packet Filter) är en kraftfull Linux-teknik som låter sandboxade program köras i kärnan. bpftrace ger en högnivåsyntax för att skriva eBPF-program. Detta är godtyckliga program som körs i kärnan och har därför stor uttryckskraft (men också en något klumpig awk-liknande syntax). Det vanligaste användningsfallet är att undersöka vilka systemanrop som anropas, inklusive aggregeringar (som antal eller latensstatistik) eller introspektion (eller till och med filtrering på) systemanropsargument.

# Spåra filöppningar i hela systemet (skrivs ut direkt)
sudo bpftrace -e 'tracepoint:syscalls:sys_enter_openat { printf("%s %s\n", comm, str(args->filename)); }'

# Räkna systemanrop per namn (skriver ut sammanfattning med Ctrl-C)
sudo bpftrace -e 'tracepoint:syscalls:sys_enter_* { @[probe] = count(); }'

Du kan också skriva eBPF-program direkt i C med en verktygskedja som bcc, som också levereras med många praktiska verktyg som biosnoop för att skriva ut latensfördelningar för diskoperationer eller opensnoop för att skriva ut alla öppnade filer.

Där strace är användbart eftersom det är lätt att “bara komma igång”, är bpftrace verktyget du ska ta till när du behöver lägre överkostnad, vill spåra genom kärnfunktioner eller behöver någon form av aggregering. Notera att bpftrace måste köras som root, och att det i allmänhet övervakar hela kärnan, inte bara en viss process. För att rikta in dig på ett specifikt program kan du filtrera på kommandonamn eller PID:

# Filtrera på kommandonamn (skriver ut sammanfattning med Ctrl-C)
sudo bpftrace -e 'tracepoint:syscalls:sys_enter_* /comm == "bash"/ { @[probe] = count(); }'

# Spåra ett specifikt kommando från start med -c (cpid = barnets PID)
sudo bpftrace -e 'tracepoint:syscalls:sys_enter_* /pid == cpid/ { @[probe] = count(); }' -c 'ls -la'

Flaggan -c kör det angivna kommandot och sätter cpid till dess PID, vilket är användbart för att spåra ett program från det ögonblick det startar. När det spårade kommandot avslutas skriver bpftrace ut de aggregerade resultaten.

Nätverksfelsökning

För nätverksproblem låter tcpdump och Wireshark dig fånga och analysera nätverkspaket:

# Fånga paket på port 80
sudo tcpdump -i any port 80

# Fånga och spara till fil för analys i Wireshark
sudo tcpdump -i any -w capture.pcap

För HTTPS-trafik gör krypteringen tcpdump mindre användbart. Verktyg som mitmproxy kan agera avlyssnande proxy för att inspektera krypterad trafik. Webbläsarens utvecklarverktyg (Network-fliken) är ofta enklaste sättet att felsöka HTTPS-förfrågningar från webbapplikationer, de visar dekrypterad data för begäran och svar, headers och tidsmätning.

Minnesfelsökning

Minnesfel, buffertöverskridningar, use-after-free, minnesläckor, är bland de farligaste och svåraste att felsöka. De kraschar ofta inte direkt utan korruptar minne på sätt som orsakar problem långt senare.

Sanitizers

Ett sätt att hitta minnesfel är att använda sanitizers, vilket är kompilatorfunktioner som instrumenterar koden för att upptäcka fel vid körning. Den mycket använda AddressSanitizer (ASan) upptäcker till exempel:

# Kompilera med AddressSanitizer
gcc -fsanitize=address -g program.c -o program
./program

Det finns flera användbara sanitizers:

Sanitizers kräver omkompilering men är tillräckligt snabba för CI-pipelines och vanlig utveckling.

Valgrind: när du inte kan omkompilera

Valgrind kör i stället programmet i något som liknar en virtuell maskin för att upptäcka minnesfel. Det är långsammare än sanitizers men kräver ingen omkompilering:

valgrind --leak-check=full ./my_program

Använd Valgrind när:

Valgrind är faktiskt en mycket kraftfull kontrollerad körmiljö, och vi kommer se mer av den senare när vi kommer till profilering.

AI för felsökning

Stora språkmodeller har blivit förvånansvärt användbara felsökningsassistenter. De är särskilt bra på vissa felsökningsuppgifter som kompletterar traditionella verktyg.

Där LLM:er glänser:

Obs om debugsymboler: För meningsfulla stackspår och felsökning, se till att dina binärer (och länkade bibliotek) kompileras med debugsymboler (flaggan -g). Felsökningsinformation lagras typiskt i DWARF-format. Dessutom gör kompilering med frame pointers (-fno-omit-frame-pointer) stackspår mer tillförlitliga, särskilt för profileringsverktyg. Utan detta kan stackspår bara visa minnesadresser eller vara ofullständiga. Detta spelar större roll för nativt kompilerade program (C++, Rust) än för Python eller Java.

Begränsningar att ha i åtanke:

Detta skiljer sig från de generella AI-kodningsförmågorna som tas upp i föreläsningen om utvecklingsmiljö. Här pratar vi specifikt om att använda LLM:er som ett hjälpmedel vid felsökning.

Profilering

Även om koden funktionellt beter sig som förväntat kanske det inte räcker om den samtidigt slukar all CPU eller allt minne. Algoritmkurser lär ofta ut big O-notation men inte hur man hittar flaskhalsar i program. Eftersom premature optimization is the root of all evil bör du lära dig om profileringsverktyg och övervakningsverktyg. De hjälper dig förstå vilka delar av programmet som tar mest tid och/eller resurser så att du kan fokusera optimering där den spelar roll.

Timing

Det enklaste sättet att mäta prestanda är att mäta tid. I många scenarier räcker det att bara skriva ut tiden som koden tog mellan två punkter.

Men wall clock-tid kan vara missvisande eftersom datorn kan köra andra processer samtidigt eller vänta på händelser. Kommandot time skiljer mellan Real, User och Sys tid:

$ time curl https://missing.csail.mit.edu &> /dev/null
real	0m0.272s
user	0m0.079s
sys	    0m0.028s

Här tog förfrågan nästan 300 millisekunder (real tid) men bara 107 ms CPU-tid (user + sys). Resten var väntan på nätverket.

Resursövervakning

Ibland är första steget i att analysera programmets prestanda att förstå faktisk resursförbrukning. Program kör ofta långsamt när de är resursbegränsade.

Visualisering av prestandadata

Människor ser mönster i grafer mycket snabbare än i tabeller med siffror. När du analyserar prestanda avslöjar plottning ofta trender, toppar och avvikelser som är osynliga i rådata.

Gör data plottbar: När du lägger till utskrifts- eller loggsatser för felsökning, överväg att formatera utdata så att den enkelt kan plottas senare. En enkel tidsstämpel och ett värde i CSV-format (1705012345,42.5) är mycket enklare att plotta än en fullständig mening. JSON-strukturerade loggar kan också parsas och plottas med minimal ansträngning. Med andra ord, logga din data på ett välstrukturerat sätt.

Snabb plottning med gnuplot: För enkel kommandoradsplottning kan gnuplot skapa grafer direkt från datafiler:

# Plotta en enkel CSV med tidsstämpel,värde
gnuplot -e "set datafile separator ','; plot 'latency.csv' using 1:2 with lines"

Iterativ utforskning med matplotlib och ggplot2: För djupare analys möjliggör Pythons matplotlib och R:s ggplot2 iterativ utforskning. Till skillnad från engångsplottning låter dessa verktyg dig snabbt skära och transformera data för att undersöka hypoteser. ggplot2:s facet-plottar är särskilt kraftfulla, du kan dela ett dataset över flera subplotar per kategori (t.ex. latens per endpoint eller tid på dygnet) för att få fram mönster som annars skulle döljas.

Exempel på användningsfall:

CPU-profilerare

Oftast när folk säger profilerare menar de CPU-profilerare. Det finns två huvudtyper:

Samplingprofilering har lägre överkostnad och är generellt att föredra i produktion.

perf: samplingsprofileraren

perf är standardprofileraren på Linux. Den kan profilera vilket program som helst utan omkompilering:

perf stat ger en snabb överblick över var tiden spenderas:

$ perf stat ./slow_program

 Performance counter stats for './slow_program':

         3,210.45 msec task-clock                #    0.998 CPUs utilized
               12      context-switches          #    3.738 /sec
                0      cpu-migrations            #    0.000 /sec
              156      page-faults               #   48.587 /sec
   12,345,678,901      cycles                    #    3.845 GHz
    9,876,543,210      instructions              #    0.80  insn per cycle
    1,234,567,890      branches                  #  384.532 M/sec
       12,345,678      branch-misses             #    1.00% of all branches

Profiler-utdata för verkliga program innehåller ofta stora mängder information. Människor är visuella och ganska dåliga på att läsa stora mängder siffror. Flamdiagram (flame graph) är en visualisering som gör profileringsdata mycket enklare att förstå.

Ett flamdiagram visar en hierarki av funktionsanrop längs Y-axeln och tidsåtgång proportionellt mot X-axeln. De är interaktiva, du kan klicka för att zooma in i specifika delar av programmet.

FlameGraph

För att generera ett flamdiagram från perf-data:

# Spela in profilering
perf record -g ./my_program

# Generera flamdiagram (kräver flamegraph-skript)
perf script | stackcollapse-perf.pl | flamegraph.pl > flamegraph.svg

Överväg att använda Speedscope för en interaktiv webbaserad flamdiagramvisare, eller Perfetto för omfattande systemnivåanalys.

Valgrinds Callgrind: spårningsprofilerare

callgrind är ett profileringsverktyg som spelar in anropshistorik och instruktionsantal för programmet. Till skillnad från samplingsprofilerare ger den exakta anropsantal och kan visa relationen mellan anropande och anropade funktioner:

# Kör med callgrind
valgrind --tool=callgrind ./my_program

# Analysera med callgrind_annotate (text) eller kcachegrind (GUI)
callgrind_annotate callgrind.out.<pid>
kcachegrind callgrind.out.<pid>

Callgrind är långsammare än samplingsprofilerare men ger exakta anropsantal och kan valfritt simulera cache-beteende (med --cache-sim=yes) om du behöver den informationen.

Om du använder ett särskilt språk kan det finnas mer specialiserade profilerare. Till exempel har Python cProfile och py-spy, Go har go tool pprof, och Rust har cargo-flamegraph (som faktiskt fungerar för alla kompilerade program!).

Minnesprofilerare

Minnesprofilerare hjälper dig förstå hur programmet använder minne över tid och hitta minnesläckor.

Valgrinds Massif

massif profilerar heap-minnesanvändning:

valgrind --tool=massif ./my_program
ms_print massif.out.<pid>

Detta visar heap-användning över tid och hjälper dig identifiera minnesläckor och överdriven allokering.

För Python ger memory-profiler rad-för-rad-information om minnesanvändning.

Benchmarking

När du behöver jämföra prestanda mellan olika implementationer eller verktyg är hyperfine utmärkt för att benchmarka kommandoradsprogram:

$ hyperfine --warmup 3 'fd -e jpg' 'find . -iname "*.jpg"'
Benchmark #1: fd -e jpg
  Time (mean ± σ):      51.4 ms ±   2.9 ms    [User: 121.0 ms, System: 160.5 ms]
  Range (min … max):    44.2 ms …  60.1 ms    56 runs

Benchmark #2: find . -iname "*.jpg"
  Time (mean ± σ):      1.126 s ±  0.101 s    [User: 141.1 ms, System: 956.1 ms]
  Range (min … max):    0.975 s …  1.287 s    10 runs

Summary
  'fd -e jpg' ran
   21.89 ± 2.33 times faster than 'find . -iname "*.jpg"'

För webbutveckling har webbläsarens utvecklarverktyg utmärkta profilerare. Se dokumentationen för Firefox Profiler och Chrome DevTools.

Övningar

Felsökning

  1. Felsök en sorteringsalgoritm: Följande pseudokod implementerar merge sort men innehåller ett programfel. Implementera den i ett språk du väljer, och använd sedan en felsökare (gdb, lldb, pdb eller din IDE:s felsökare) för att hitta och åtgärda programfelet.

    function merge_sort(arr):
    if length(arr) <= 1:
        return arr
    mid = length(arr) / 2
    left = merge_sort(arr[0..mid])
    right = merge_sort(arr[mid..end])
    return merge(left, right)

function merge(left, right):
    result = []
    i = 0, j = 0
    while i < length(left) AND j < length(right):
        if left[i] <= right[j]:
            append result, left[i]
            i = i + 1
        else:
            append result, right[i]
            j = j + 1
    append remaining elements from left and right
    return result

    Testvektor: merge_sort([3, 1, 4, 1, 5, 9, 2, 6]) ska returnera [1, 1, 2, 3, 4, 5, 6, 9]. Använd brytpunkter och stega genom merge-funktionen för att hitta var felaktigt element väljs.

  2. Installera rr och använd omvänd felsökning (reverse debugging) för att hitta ett korruptionsfel. Spara detta program som corruption.c:

    #include <stdio.h>

typedef struct {
    int id;
    int scores[3];
} Student;

Student students[2];

void init() {
    students[0].id = 1001;
    students[0].scores[0] = 85;
    students[0].scores[1] = 92;
    students[0].scores[2] = 78;

    students[1].id = 1002;
    students[1].scores[0] = 90;
    students[1].scores[1] = 88;
    students[1].scores[2] = 95;
}

void curve_scores(int student_idx, int curve) {
    for (int i = 0; i < 4; i++) {
        students[student_idx].scores[i] += curve;
    }
}

int main() {
    init();
    printf("=== Initial state ===\n");
    printf("Student 0: id=%d\n", students[0].id);
    printf("Student 1: id=%d\n", students[1].id);

    curve_scores(0, 5);

    printf("\n=== After curving ===\n");
    printf("Student 0: id=%d\n", students[0].id);
    printf("Student 1: id=%d\n", students[1].id);

    if (students[1].id != 1002) {
        printf("\nERROR: Student 1's ID was corrupted! Expected 1002, got %d\n",
               students[1].id);
        return 1;
    }
    return 0;
}

    Kompilera med gcc -g corruption.c -o corruption och kör programmet. Student 1:s ID blir korrupt, men korruptionen händer i en funktion som bara rör student 0. Använd rr record ./corruption och rr replay för att hitta boven. Sätt en watchpoint på students[1].id och använd reverse-continue efter korruptionen för att hitta exakt vilken kodrad som skrev över värdet.

  3. Felsök ett minnesfel med AddressSanitizer. Spara detta som uaf.c:

    #include <stdlib.h>
#include <string.h>
#include <stdio.h>

int main() {
    char *greeting = malloc(32);
    strcpy(greeting, "Hello, world!");
    printf("%s\n", greeting);

    free(greeting);

    greeting[0] = 'J';
    printf("%s\n", greeting);

    return 0;
}

    Kompilera och kör först utan sanitizers: gcc uaf.c -o uaf && ./uaf. Det kan verka fungera. Kompilera nu med AddressSanitizer: gcc -fsanitize=address -g uaf.c -o uaf && ./uaf. Läs felrapporten. Vilket programfel hittar ASan? Fixa problemet den identifierar.

  4. Använd strace (Linux) eller dtruss (macOS) för att spåra systemanropen som görs av ett kommando som ls -l. Vilka systemanrop görs? Prova att spåra ett mer komplext program och se vilka filer det öppnar.

  5. Använd en LLM för att hjälpa till att felsöka ett kryptiskt felmeddelande. Prova att kopiera ett kompilatorfel (särskilt från C++-templates eller Rust) och be om förklaring och fix. Prova att klistra in delar av utdata från strace eller AddressSanitizer.

Profilering

  1. Använd perf stat för att få grundläggande prestandastatistik för ett valfritt program. Vad betyder de olika räknarna?

  2. Profilera med perf record. Spara detta som slow.c:

    #include <math.h>
#include <stdio.h>

double slow_computation(int n) {
    double result = 0;
    for (int i = 0; i < n; i++) {
        for (int j = 0; j < 1000; j++) {
            result += sin(i * j) * cos(i + j);
        }
    }
    return result;
}

int main() {
    double r = 0;
    for (int i = 0; i < 100; i++) {
        r += slow_computation(1000);
    }
    printf("Result: %f\n", r);
    return 0;
}

    Kompilera med debugsymboler: gcc -g -O2 slow.c -o slow -lm. Kör perf record -g ./slow, sedan perf report för att se var tid spenderas. Prova att generera ett flamdiagram med flamegraph-skripten.

  3. Använd hyperfine för att benchmarka två olika implementationer av samma uppgift (t.ex. find vs fd, grep vs ripgrep, eller två versioner av din egen kod).

  4. Använd htop för att övervaka systemet medan du kör ett resursintensivt program. Prova att använda taskset för att begränsa vilka CPU:er en process kan använda: taskset --cpu-list 0,2 stress -c 3. Varför använder inte stress tre CPU:er?

  5. Ett vanligt problem är att en port du vill lyssna på redan används av en annan process. Lär dig hitta den processen: kör först python -m http.server 4444 för att starta en minimal webbserver på port 4444. Kör i en separat terminal ss -tlnp | grep 4444 för att hitta processen. Avsluta den med kill <PID>.

Edit this page.

Licensed under CC BY-NC-SA.