Strace i Linux: historie, design og brug

Strace i Linux: historie, design og brug

I Unix-lignende operativsystemer sker et programs kommunikation med omverdenen og styresystemet gennem et lille sæt funktioner – systemkald. Dette betyder, at det til debugging-formål kan være nyttigt at spionere på systemopkald, der udføres af processer.

Et hjælpeprogram hjælper dig med at overvåge programmers "intime liv" på Linux strace, som er emnet for denne artikel. Eksempler på brug af spionudstyr er ledsaget af en kort historie strace og en beskrivelse af udformningen af ​​sådanne programmer.

Indhold

Arternes oprindelse

Hovedgrænsefladen mellem programmer og OS-kernen i Unix er systemkald. systemopkald, syscalls), programmernes interaktion med omverdenen sker udelukkende gennem dem.

Men i den første offentlige version af Unix (Version 6 Unix, 1975) var der ingen praktiske måder at spore adfærden af ​​brugerprocesser. For at løse dette problem vil Bell Labs opdatere til den næste version (Version 7 Unix, 1979) foreslog et nyt systemkald - ptrace.

ptrace blev udviklet primært til interaktive debuggere, men i slutningen af ​​80'erne (i den kommercielle æra System V udgivelse 4) på dette grundlag dukkede snævert fokuserede debuggere op - systemopkaldssporere - og blev meget brugt.

første den samme version af strace blev udgivet af Paul Cronenburg på comp.sources.sun-mailinglisten i 1992 som et alternativ til et lukket hjælpeprogram trace fra Sun. Både klonen og originalen var beregnet til SunOS, men i 1994 strace blev overført til System V, Solaris og det stadig mere populære Linux.

I dag understøtter strace kun Linux og er afhængig af det samme ptrace, bevokset med mange forlængelser.

Moderne (og meget aktiv) vedligeholder straceDmitry Levin. Takket være ham fik værktøjet avancerede funktioner såsom fejlinjektion i systemkald, support til en bred vifte af arkitekturer og, vigtigst af alt, maskot. Uofficielle kilder hævder, at valget faldt på strudsen på grund af konsonansen mellem det russiske ord "struds" og det engelske ord "strace".

Det er også vigtigt, at ptrace-systemkaldet og sporingerne aldrig blev inkluderet i POSIX, på trods af en lang historie og implementering i Linux, FreeBSD, OpenBSD og traditionel Unix.

Strace-enhed i en nøddeskal: Piglet Trace

"Du forventes ikke at forstå dette" (Dennis Ritchie, kommentar i Version 6 Unix-kildekoden)

Siden den tidlige barndom kan jeg ikke fordrage sorte kasser: Jeg legede ikke med legetøj, men forsøgte at forstå deres struktur (voksne brugte ordet "brød", men tror ikke på de onde tunger). Måske er det derfor, den uformelle kultur i den første Unix og den moderne open source-bevægelse er så tæt på mig.

I denne artikels formål er det urimeligt at adskille kildekoden til strace, som er vokset gennem årtier. Men der skal ikke være hemmeligheder tilbage for læserne. Derfor, for at vise princippet om drift af sådanne strace-programmer, vil jeg give koden til en miniature-sporing - Grisespor (ptr). Det ved ikke, hvordan man gør noget særligt, men det vigtigste er programmets systemkald - det udsender:

$ gcc examples/piglet-trace.c -o ptr
$ ptr echo test > /dev/null
BRK(12) -> 94744690540544
ACCESS(21) -> 18446744073709551614
ACCESS(21) -> 18446744073709551614
unknown(257) -> 3
FSTAT(5) -> 0
MMAP(9) -> 140694657216512
CLOSE(3) -> 0
ACCESS(21) -> 18446744073709551614
unknown(257) -> 3
READ(0) -> 832
FSTAT(5) -> 0
MMAP(9) -> 140694657208320
MMAP(9) -> 140694650953728
MPROTECT(10) -> 0
MMAP(9) -> 140694655045632
MMAP(9) -> 140694655070208
CLOSE(3) -> 0
unknown(158) -> 0
MPROTECT(10) -> 0
MPROTECT(10) -> 0
MPROTECT(10) -> 0
MUNMAP(11) -> 0
BRK(12) -> 94744690540544
BRK(12) -> 94744690675712
unknown(257) -> 3
FSTAT(5) -> 0
MMAP(9) -> 140694646390784
CLOSE(3) -> 0
FSTAT(5) -> 0
IOCTL(16) -> 18446744073709551591
WRITE(1) -> 5
CLOSE(3) -> 0
CLOSE(3) -> 0
unknown(231)
Tracee terminated

Piglet Trace genkender omkring hundredvis af Linux-systemkald (se. bord) og virker kun på x86-64-arkitektur. Dette er tilstrækkeligt til uddannelsesformål.

Lad os se på vores klons arbejde. I tilfælde af Linux bruger debuggere og sporere, som nævnt ovenfor, ptrace-systemkaldet. Det fungerer ved at overføre kommandoidentifikatorerne i det første argument, som vi kun behøver PTRACE_TRACEME, PTRACE_SYSCALL и PTRACE_GETREGS.

Sporen starter i den sædvanlige Unix-stil: fork(2) lancerer en børneproces, som igen bruger exec(3) lancerer det undersøgte program. Den eneste subtilitet her er udfordringen ptrace(PTRACE_TRACEME) før exec: Den underordnede proces forventer, at forældreprocessen overvåger den:

pid_t child_pid = fork();
switch (child_pid) {
case -1:
    err(EXIT_FAILURE, "fork");
case 0:
    /* Child here */
    /* A traced mode has to be enabled. A parent will have to wait(2) for it
     * to happen. */
    ptrace(PTRACE_TRACEME, 0, NULL, NULL);
    /* Replace itself with a program to be run. */
    execvp(argv[1], argv + 1);
    err(EXIT_FAILURE, "exec");
}

Forældreprocessen skulle nu kalde wait(2) i den underordnede proces, det vil sige, sørg for, at skiftet til sporingstilstand er sket:

/* Parent */

/* First we wait for the child to set the traced mode (see
 * ptrace(PTRACE_TRACEME) above) */
if (waitpid(child_pid, NULL, 0) == -1)
    err(EXIT_FAILURE, "traceme -> waitpid");

På dette tidspunkt er forberedelserne færdige, og du kan fortsætte direkte til at spore systemopkald i en endeløs løkke.

opkald ptrace(PTRACE_SYSCALL) garanterer, at efterfølgende wait forælder vil fuldføre enten før systemkaldet udføres eller umiddelbart efter det er fuldført. Mellem to opkald kan du udføre en hvilken som helst handling: erstatte opkaldet med et alternativt, ændre argumenterne eller returværdien.

Vi skal bare kalde kommandoen to gange ptrace(PTRACE_GETREGS)for at få registerstatus rax før opkaldet (systemopkaldsnummer) og umiddelbart efter (returværdi).

Faktisk, cyklussen:

/* A system call tracing loop, one interation per call. */
for (;;) {
    /* A non-portable structure defined for ptrace/GDB/strace usage mostly.
     * It allows to conveniently dump and access register state using
     * ptrace. */
    struct user_regs_struct registers;

    /* Enter syscall: continue execution until the next system call
     * beginning. Stop right before syscall.
     *
     * It's possible to change the system call number, system call
     * arguments, return value or even avoid executing the system call
     * completely. */
  if (ptrace(PTRACE_SYSCALL, child_pid, NULL, NULL) == -1)
      err(EXIT_FAILURE, "enter_syscall");
  if (waitpid(child_pid, NULL, 0) == -1)
      err(EXIT_FAILURE, "enter_syscall -> waitpid");

  /* According to the x86-64 system call convention on Linux (see man 2
   * syscall) the number identifying a syscall should be put into the rax
   * general purpose register, with the rest of the arguments residing in
   * other general purpose registers (rdi,rsi, rdx, r10, r8, r9). */
  if (ptrace(PTRACE_GETREGS, child_pid, NULL, &registers) == -1)
      err(EXIT_FAILURE, "enter_syscall -> getregs");

  /* Note how orig_rax is used here. That's because on x86-64 rax is used
   * both for executing a syscall, and returning a value from it. To
   * differentiate between the cases both rax and orig_rax are updated on
   * syscall entry/exit, and only rax is updated on exit. */
  print_syscall_enter(registers.orig_rax);

  /* Exit syscall: execute of the syscall, and stop on system
   * call exit.
   *
   * More system call tinkering possible: change the return value, record
   * time it took to finish the system call, etc. */
  if (ptrace(PTRACE_SYSCALL, child_pid, NULL, NULL) == -1)
      err(EXIT_FAILURE, "exit_syscall");
  if (waitpid(child_pid, NULL, 0) == -1)
      err(EXIT_FAILURE, "exit_syscall -> waitpid");

  /* Retrieve register state again as we want to inspect system call
   * return value. */
  if (ptrace(PTRACE_GETREGS, child_pid, NULL, &registers) == -1) {
      /* ESRCH is returned when a child terminates using a syscall and no
       * return value is possible, e.g. as a result of exit(2). */
      if (errno == ESRCH) {
          fprintf(stderr, "nTracee terminatedn");
          break;
      }
      err(EXIT_FAILURE, "exit_syscall -> getregs");
  }

  /* Done with this system call, let the next iteration handle the next
   * one */
  print_syscall_exit(registers.rax);
}

Det er hele sporstoffet. Nu ved du, hvor du skal starte den næste portering DTrace på Linux.

Grundlæggende: køre et program, der kører strace

Som en første use case strace, måske er det værd at citere den enkleste metode - at starte en applikation, der kører strace.

For ikke at dykke ned i den endeløse liste over opkald i et typisk program, skriver vi minimum program om write:

int main(int argc, char *argv[])
{
    char str[] = "write me to stdoutn";
    /* write(2) is a simple wrapper around a syscall so it should be easy to
     * find in the syscall trace. */
    if (sizeof(str) != write(STDOUT_FILENO, str, sizeof(str))){
        perror("write");
        return EXIT_FAILURE;
    }
    return EXIT_SUCCESS;
}

Lad os bygge programmet og sikre os, at det virker:

$ gcc examples/write-simple.c -o write-simple
$ ./write-simple
write me to stdout

Og endelig, lad os køre det under strace-kontrol:

$ strace ./write-simple
pexecve("./write", ["./write"], 0x7ffebd6145b0 /* 71 vars */) = 0
brk(NULL)                               = 0x55ff5489e000
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=197410, ...}) = 0
mmap(NULL, 197410, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f7a2a633000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "177ELF21133>1260342"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=2030544, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f7a2a631000
mmap(NULL, 4131552, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f7a2a04c000
mprotect(0x7f7a2a233000, 2097152, PROT_NONE) = 0
mmap(0x7f7a2a433000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1e7000) = 0x7f7a2a433000
mmap(0x7f7a2a439000, 15072, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f7a2a439000
close(3)                                = 0
arch_prctl(ARCH_SET_FS, 0x7f7a2a6324c0) = 0
mprotect(0x7f7a2a433000, 16384, PROT_READ) = 0
mprotect(0x55ff52b52000, 4096, PROT_READ) = 0
mprotect(0x7f7a2a664000, 4096, PROT_READ) = 0
munmap(0x7f7a2a633000, 197410)          = 0
write(1, "write me to stdoutn", 20write me to stdout
)  = 20
exit_group(0)                           = ?

Meget "ordrig" og ikke særlig lærerig. Der er to problemer her: programmets output er blandet med outputtet strace og en overflod af systemopkald, der ikke interesserer os.

Du kan adskille programmets standardoutputstrøm og strace-fejloutput ved hjælp af -o-switchen, som omdirigerer listen over systemkald til en argumentfil.

Det er tilbage at håndtere problemet med "ekstra" opkald. Lad os antage, at vi kun er interesserede i opkald write. Nøgle -e giver dig mulighed for at angive udtryk, som systemopkald vil blive filtreret efter. Den mest populære tilstandsmulighed er naturligvis, trace=*, hvormed du kun kan forlade de opkald, der interesserer os.

Når det bruges samtidigt -o и -e vi får:

$ strace -e trace=write -owrite-simple.log ./write-simple
write me to stdout
$ cat write-simple.log
write(1, "write me to stdoutn", 20
)  = 20
+++ exited with 0 +++

Så du kan se, det er meget nemmere at læse.

Du kan også fjerne systemopkald, for eksempel dem, der er relateret til hukommelsesallokering og frigivelse:

$ strace -e trace=!brk,mmap,mprotect,munmap -owrite-simple.log ./write-simple
write me to stdout
$ cat write-simple.log
execve("./write-simple", ["./write-simple"], 0x7ffe9972a498 /* 69 vars */) = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=124066, ...}) = 0
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "177ELF21133>1260342"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=2030544, ...}) = 0
close(3)                                = 0
arch_prctl(ARCH_SET_FS, 0x7f00f0be74c0) = 0
write(1, "write me to stdoutn", 20)  = 20
exit_group(0)                           = ?
+++ exited with 0 +++

Bemærk det undslupne udråbstegn på listen over ekskluderede opkald: dette kræves af kommandoskallen. Shell).

I min version af glibc afslutter et systemkald processen exit_group, ikke traditionel _exit. Dette er vanskeligheden ved at arbejde med systemopkald: grænsefladen, som programmøren arbejder med, er ikke direkte relateret til systemopkald. Desuden ændres det regelmæssigt afhængigt af implementering og platform.

Grundlæggende: Deltag i processen i farten

I første omgang kalder ptrace-systemet, som det blev bygget på strace, kunne kun bruges, når programmet kører i en speciel tilstand. Denne begrænsning kan have lød rimelig i dagene af Version 6 Unix. I dag er dette ikke længere nok: nogle gange er du nødt til at undersøge problemerne med et fungerende program. Et typisk eksempel er en proces, der er blokeret på et håndtag eller sover. Derfor moderne strace kan tilslutte sig processer i farten.

Fryseeksempel programmer:

int main(int argc, char *argv[])
{
    (void) argc; (void) argv;

    char str[] = "write men";

    write(STDOUT_FILENO, str, sizeof(str));

    /* Sleep indefinitely or until a signal arrives */
    pause();

    write(STDOUT_FILENO, str, sizeof(str));

    return EXIT_SUCCESS;
}

Lad os bygge programmet og sørge for, at det er frosset:

$ gcc examples/write-sleep.c -o write-sleep
$ ./write-sleep
./write-sleep
write me
^C
$

Lad os nu prøve at slutte os til det:

$ ./write-sleep &
[1] 15329
write me
$ strace -p 15329
strace: Process 15329 attached
pause(
^Cstrace: Process 15329 detached
 <detached ...>

Program blokeret ved opkald pause. Lad os se, hvordan hun reagerer på signalerne:

$ strace -o write-sleep.log -p 15329 &
strace: Process 15329 attached
$
$ kill -CONT 15329
$ cat write-sleep.log
pause()                                 = ? ERESTARTNOHAND (To be restarted if no handler)
--- SIGCONT {si_signo=SIGCONT, si_code=SI_USER, si_pid=14989, si_uid=1001} ---
pause(
$
$ kill -TERM 15329
$ cat write-sleep.log
pause()                                 = ? ERESTARTNOHAND (To be restarted if no handler)
--- SIGCONT {si_signo=SIGCONT, si_code=SI_USER, si_pid=14989, si_uid=1001} ---
pause()                                 = ? ERESTARTNOHAND (To be restarted if no handler)
--- SIGTERM {si_signo=SIGTERM, si_code=SI_USER, si_pid=14989, si_uid=1001} ---
+++ killed by SIGTERM +++

Vi lancerede det frosne program og sluttede os til det vha strace. To ting blev klart: Pause systemkaldet ignorerer signaler uden handlere, og mere interessant overvåger strace ikke kun systemopkald, men også indgående signaler.

Eksempel: Sporing af børneprocesser

Arbejde med processer gennem et opkald fork - grundlaget for alle Unixer. Lad os se, hvordan strace fungerer med et procestræ ved at bruge eksemplet på en simpel "opdræt" programmer:

int main(int argc, char *argv[])
{
    pid_t parent_pid = getpid();
    pid_t child_pid = fork();
    if (child_pid == 0) {
        /* A child is born! */
        child_pid = getpid();

        /* In the end of the day printf is just a call to write(2). */
        printf("child (self=%d)n", child_pid);
        exit(EXIT_SUCCESS);
    }

    printf("parent (self=%d, child=%d)n", parent_pid, child_pid);

    wait(NULL);

    exit(EXIT_SUCCESS);
}

Her opretter den originale proces en underordnet proces, der både skriver til standardoutput:

$ gcc examples/fork-write.c -o fork-write
$ ./fork-write
parent (self=11274, child=11275)
child (self=11275)

Som standard vil vi kun se systemopkald fra forældreprocessen:

$ strace -e trace=write -ofork-write.log ./fork-write
child (self=22049)
parent (self=22048, child=22049)
$ cat fork-write.log
write(1, "parent (self=22048, child=22049)"..., 33) = 33
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=22049, si_uid=1001, si_status=0, si_utime=0, si_stime=0} ---
+++ exited with 0 +++

Flaget hjælper dig med at spore hele procestræet -f, hvilken strace overvåger systemkald i underordnede processer. Dette tilføjes til hver linje af output pid proces, der laver et systemoutput:

$ strace -f -e trace=write -ofork-write.log ./fork-write
parent (self=22710, child=22711)
child (self=22711)
$ cat fork-write.log
22710 write(1, "parent (self=22710, child=22711)"..., 33) = 33
22711 write(1, "child (self=22711)n", 19) = 19
22711 +++ exited with 0 +++
22710 --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=22711, si_uid=1001, si_status=0, si_utime=0, si_stime=0} ---
22710 +++ exited with 0 +++

I denne sammenhæng kan filtrering efter gruppe af systemkald være nyttig:

$ strace -f -e trace=%process -ofork-write.log ./fork-write
parent (self=23610, child=23611)
child (self=23611)
$ cat fork-write.log
23610 execve("./fork-write", ["./fork-write"], 0x7fff696ff720 /* 63 vars */) = 0
23610 arch_prctl(ARCH_SET_FS, 0x7f3d03ba44c0) = 0
23610 clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f3d03ba4790) = 23611
23610 wait4(-1,  <unfinished ...>
23611 exit_group(0)                     = ?
23611 +++ exited with 0 +++
23610 <... wait4 resumed> NULL, 0, NULL) = 23611
23610 --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=23611, si_uid=1001, si_status=0, si_utime=0, si_stime=0} ---
23610 exit_group(0)                     = ?
23610 +++ exited with 0 +++

Hvilket systemkald bruges i øvrigt til at oprette en ny proces?

Eksempel: filstier i stedet for håndtag

At kende filbeskrivelser er bestemt nyttigt, men navnene på de specifikke filer, som et program får adgang til, kan også være nyttige.

den næste program skriver linjen til den midlertidige fil:

void do_write(int out_fd)
{
    char str[] = "write me to a filen";

    if (sizeof(str) != write(out_fd, str, sizeof(str))){
        perror("write");
        exit(EXIT_FAILURE);
    }
}

int main(int argc, char *argv[])
{
    char tmp_filename_template[] = "/tmp/output_fileXXXXXX";

    int out_fd = mkstemp(tmp_filename_template);
    if (out_fd == -1) {
        perror("mkstemp");
        exit(EXIT_FAILURE);
    }

    do_write(out_fd);

    return EXIT_SUCCESS;
}

Under et normalt opkald strace vil vise værdien af ​​det deskriptornummer, der er sendt til systemkaldet:

$ strace -e trace=write -o write-tmp-file.log ./write-tmp-file
$ cat write-tmp-file.log
write(3, "write me to a filen", 20)  = 20
+++ exited with 0 +++

Med et flag -y Værktøjet viser stien til filen, som beskrivelsen svarer til:

$ strace -y -e trace=write -o write-tmp-file.log ./write-tmp-file
$ cat write-tmp-file.log
write(3</tmp/output_fileCf5MyW>, "write me to a filen", 20) = 20
+++ exited with 0 +++

Eksempel: Filadgangssporing

En anden nyttig funktion: vis kun systemopkald forbundet med en bestemt fil. Næste program tilføjer en linje til en vilkårlig fil, der sendes som et argument:

void do_write(int out_fd)
{
    char str[] = "write me to a filen";

    if (sizeof(str) != write(out_fd, str, sizeof(str))){
        perror("write");
        exit(EXIT_FAILURE);
    }
}

int main(int argc, char *argv[])
{
    /*
     * Path will be provided by the first program argument.
     *  */
    const char *path = argv[1];

    /*
     * Open an existing file for writing in append mode.
     *  */
    int out_fd = open(path, O_APPEND | O_WRONLY);
    if (out_fd == -1) {
        perror("open");
        exit(EXIT_FAILURE);
    }

    do_write(out_fd);

    return EXIT_SUCCESS;
}

Som standard strace viser en masse unødvendig information. Flag -P med et argument får strace kun til at udskrive opkald til den angivne fil:

$ strace -y -P/tmp/test_file.log -o write-file.log ./write-file /tmp/test_file.log
$ cat write-file.log
openat(AT_FDCWD, "/tmp/test_file.log", O_WRONLY|O_APPEND) = 3</tmp/test_file.log>
write(3</tmp/test_file.log>, "write me to a filen", 20) = 20
+++ exited with 0 +++

Eksempel: Flertrådede programmer

Hjælpeprogram strace kan også hjælpe, når du arbejder med multi-threaded programmet. Følgende program skriver til standard output fra to streams:

void *thread(void *arg)
{
    (void) arg;

    printf("Secondary thread: workingn");
    sleep(1);
    printf("Secondary thread: donen");

    return NULL;
}

int main(int argc, char *argv[])
{
    printf("Initial thread: launching a threadn");

    pthread_t thr;
    if (0 != pthread_create(&thr, NULL, thread, NULL)) {
        fprintf(stderr, "Initial thread: failed to create a thread");
        exit(EXIT_FAILURE);
    }

    printf("Initial thread: joining a threadn");
    if (0 != pthread_join(thr, NULL)) {
        fprintf(stderr, "Initial thread: failed to join a thread");
        exit(EXIT_FAILURE);
    };

    printf("Initial thread: done");

    exit(EXIT_SUCCESS);
}

Det skal naturligvis sammensættes med en særlig hilsen til linkeren - -pthread-flaget:

$ gcc examples/thread-write.c -pthread -o thread-write
$ ./thread-write
/thread-write
Initial thread: launching a thread
Initial thread: joining a thread
Secondary thread: working
Secondary thread: done
Initial thread: done
$

flag -f, som i tilfældet med almindelige processer, tilføjer processens pid til begyndelsen af ​​hver linje.

Naturligvis taler vi ikke om en trådidentifikator i betydningen implementeringen af ​​POSIX Threads-standarden, men om det antal, der bruges af opgaveplanlæggeren i Linux. Fra sidstnævntes synspunkt er der ingen processer eller tråde - der er opgaver, der skal fordeles mellem de tilgængelige kerner i maskinen.

Når du arbejder i flere tråde, bliver systemkald for mange:

$ strace -f -othread-write.log ./thread-write
$ wc -l thread-write.log
60 thread-write.log

Det giver mening kun at begrænse dig til processtyring og systemkald write:

$ strace -f -e trace="%process,write" -othread-write.log ./thread-write
$ cat thread-write.log
18211 execve("./thread-write", ["./thread-write"], 0x7ffc6b8d58f0 /* 64 vars */) = 0
18211 arch_prctl(ARCH_SET_FS, 0x7f38ea3b7740) = 0
18211 write(1, "Initial thread: launching a thre"..., 35) = 35
18211 clone(child_stack=0x7f38e9ba2fb0, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tidptr=0x7f38e9ba39d0, tls=0x7f38e9ba3700, child_tidptr=0x7f38e9ba39d0) = 18212
18211 write(1, "Initial thread: joining a thread"..., 33) = 33
18212 write(1, "Secondary thread: workingn", 26) = 26
18212 write(1, "Secondary thread: donen", 23) = 23
18212 exit(0)                           = ?
18212 +++ exited with 0 +++
18211 write(1, "Initial thread: done", 20) = 20
18211 exit_group(0)                     = ?
18211 +++ exited with 0 +++

Forresten spørgsmål. Hvilket systemkald bruges til at oprette en ny tråd? Hvordan adskiller denne opfordring til tråde sig fra opfordringen til processer?

Master class: processtak på tidspunktet for et systemkald

En af de for nylig dukkede op strace funktioner - visning af stakken af ​​funktionsopkald på tidspunktet for systemkaldet. Enkel eksempel:

void do_write(void)
{
    char str[] = "write me to stdoutn";
    if (sizeof(str) != write(STDOUT_FILENO, str, sizeof(str))){
        perror("write");
        exit(EXIT_FAILURE);
    }
}

int main(int argc, char *argv[])
{
    do_write();
    return EXIT_SUCCESS;
}

Naturligvis bliver programmet output meget omfangsrigt, og ud over flaget -k (opkaldsstabelvisning), giver det mening at filtrere systemkald efter navn:

$ gcc examples/write-simple.c -o write-simple
$ strace -k -e trace=write -o write-simple.log ./write-simple
write me to stdout
$ cat write-simple.log
write(1, "write me to stdoutn", 20)  = 20
 > /lib/x86_64-linux-gnu/libc-2.27.so(__write+0x14) [0x110154]
 > /home/vkazanov/projects-my/strace-post/write-simple(do_write+0x50) [0x78a]
 > /home/vkazanov/projects-my/strace-post/write-simple(main+0x14) [0x7d1]
 > /lib/x86_64-linux-gnu/libc-2.27.so(__libc_start_main+0xe7) [0x21b97]
 > /home/vkazanov/projects-my/strace-post/write-simple(_start+0x2a) [0x65a]
+++ exited with 0 +++

Master class: fejlinjektion

Og endnu en ny og meget nyttig funktion: fejlinjektion. Her program, skriver to linjer til outputstrømmen:

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

void do_write(const char *str, ssize_t len)
{
    if (len != write(STDOUT_FILENO, str, (size_t)len)){
        perror("write");
        exit(EXIT_FAILURE);
    }
}

int main(int argc, char *argv[])
{
    (void) argc; (void) argv;

    char str1[] = "write me 1n";
    do_write(str1, sizeof(str1));

    char str2[] = "write me 2n";
    do_write(str2, sizeof(str2));

    return EXIT_SUCCESS;
}

Lad os spore begge skriveopkald:

$ gcc examples/write-twice.c -o write-twice
$ ./write-twice
write me 1
write me 2
$ strace -e trace=write -owrite-twice.log ./write-twice
write me 1
write me 2
$ cat write-twice.log
write(1, "write me 1n", 12)          = 12
write(1, "write me 2n", 12)          = 12
+++ exited with 0 +++

Nu bruger vi udtrykket injectfor at indsætte en fejl EBADF i alle skriveopkald:

$ strace -e trace=write -e inject=write:error=EBADF -owrite-twice.log ./write-twice
$ cat write-twice.log
write(1, "write me 1n", 12)          = -1 EBADF (Bad file descriptor) (INJECTED)
write(3, "write: Bad file descriptorn", 27) = -1 EBADF (Bad file descriptor) (INJECTED)
+++ exited with 1 +++

Det er interessant, hvilke fejl der returneres alle udfordringer write, inklusive opkaldet skjult bag perror. Det giver kun mening at returnere en fejl for det første af opkaldene:

$ strace -e trace=write -e inject=write:error=EBADF:when=1 -owrite-twice.log ./write-twice
write: Bad file descriptor
$ cat write-twice.log
write(1, "write me 1n", 12)          = -1 EBADF (Bad file descriptor) (INJECTED)
write(3, "write: Bad file descriptorn", 27) = 27
+++ exited with 1 +++

Eller den anden:

$ strace -e trace=write -e inject=write:error=EBADF:when=2 -owrite-twice.log ./write-twice
write me 1
write: Bad file descriptor
$ cat write-twice.log
write(1, "write me 1n", 12)          = 12
write(1, "write me 2n", 12)          = -1 EBADF (Bad file descriptor) (INJECTED)
write(3, "write: Bad file descriptorn", 27) = 27
+++ exited with 1 +++

Det er ikke nødvendigt at angive fejltypen:

$ strace -e trace=write -e fault=write:when=1 -owrite-twice.log ./write-twice
$ cat write-twice.log
write(1, "write me 1n", 12)          = -1 ENOSYS (Function not implemented) (INJECTED)
write(3, "write: Function not implementedn", 32) = 32
+++ exited with 1 +++

I kombination med andre flag kan du "bryde" adgangen til en bestemt fil. Eksempel:

$ strace -y -P/tmp/test_file.log -e inject=file:error=ENOENT -o write-file.log ./write-file /tmp/test_file.log
open: No such file or directory
$ cat write-file.log
openat(AT_FDCWD, "/tmp/test_file.log", O_WRONLY|O_APPEND) = -1 ENOENT (No such file or directory) (INJECTED)
+++ exited with 1 +++

Udover fejlindsprøjtning, man kan indføre forsinkelser ved opkald eller modtagelse af signaler.

efterskrift

Hjælpeprogram strace - et enkelt og pålideligt værktøj. Men ud over systemkald kan andre aspekter af driften af ​​programmer og operativsystemet fejlsøges. For eksempel kan den spore opkald til dynamisk forbundne biblioteker. spor, kan de undersøge driften af ​​operativsystemet SystemTap и ftrace, og giver dig mulighed for dybt at undersøge programmets ydeevne perf. Ikke desto mindre er det det strace - den første forsvarslinje i tilfælde af problemer med mine egne og andres programmer, og jeg bruger den mindst et par gange om ugen.

Kort sagt, hvis du elsker Unix, så læs man 1 strace og kig gerne på dine programmer!

Kilde: www.habr.com

Tilføj en kommentar