Strace w Linuksie: historia, urządzenie i zastosowanie

Strace w Linuksie: historia, urządzenie i zastosowanie

W systemach operacyjnych typu Unix program komunikuje się ze światem zewnętrznym i systemem operacyjnym za pośrednictwem małego zestawu funkcji - wywołań systemowych. Dlatego do celów debugowania przydatne jest szpiegowanie uruchomionych procesów za pomocą wywołań systemowych.

Narzędzie pomaga monitorować „intymne życie” programów w systemie Linux stracektóremu poświęcony jest ten artykuł. Do przykładów użycia sprzętu „szpiegowskiego” dołączona jest krótka historia. strace i opis urządzenia takich programów.

Zawartość

Pochodzenie gatunków

Głównym interfejsem pomiędzy programami a jądrem OC w Unixie są wywołania systemowe. wywołania systemowe, wywołania systemowe), interakcja programów ze światem zewnętrznym odbywa się wyłącznie za ich pośrednictwem.

Ale w pierwszej publicznej wersji Uniksa (Wersja 6 Uniksa, 1975) nie było wygodnych sposobów śledzenia zachowania procesów użytkownika. Aby rozwiązać ten problem, Bell Labs przejdzie do następnej wersji (Wersja 7 Uniksa, 1979) zaproponował nowe wywołanie systemowe - ptrace.

ptrace został opracowany głównie dla interaktywnych debuggerów, ale pod koniec lat 80-tych (w dobie komercyjnego już Wersja 4 Systemu V) na tej podstawie pojawiły się i stały się powszechnie stosowane wąsko ukierunkowane debuggery - znaczniki wywołań systemowych.

pierwszy ta sama wersja strace została opublikowana przez Paula Cronenburga na liście mailingowej comp.sources.sun w 1992 roku jako alternatywa dla zastrzeżonego narzędzia trace od słońca. Zarówno klon, jak i oryginał były przeznaczone dla SunOS, ale do 1994 roku strace został przeniesiony na System V, Solaris i coraz popularniejszy Linux.

Obecnie strace obsługuje tylko Linuksa i na nim polega ptrace, porośnięty wieloma dobudówkami.

Nowoczesny (i bardzo aktywny) opiekun strace - Dmitrij Levin. Dzięki niemu narzędzie zyskało zaawansowane funkcje, takie jak wstrzykiwanie błędów do wywołań systemowych, obsługa szerokiej gamy architektur i, co najważniejsze, maskotka. Nieoficjalne źródła podają, że wybór padł na strusia ze względu na współbrzmienie rosyjskiego słowa „struś” z angielskim słowem „strace”.

Co istotne, wywołanie systemowe ptrace i znaczniki nigdy nie zostały uwzględnione w POSIX, pomimo ich długiej historii i implementacji w Linuksie, FreeBSD, OpenBSD i tradycyjnych Uniksach.

Urządzenie strace w skrócie: Piglet Trace

„Nie oczekuje się od ciebie, że to zrozumiesz” (Dennis Ritchie, komentarz w kodzie źródłowym wersji 6 Uniksa)

Od wczesnego dzieciństwa nienawidzę czarnych skrzynek: nie bawiłem się zabawkami, ale próbowałem rozgryźć ich urządzenie (dorośli używali słowa „spłukany”, ale nie wierzą złym językom). Być może dlatego nieformalna kultura pierwszych Uniksów i współczesny ruch open source są mi tak bliskie.

W ramach tego artykułu nieuzasadnione jest demontowanie kodu źródłowego strace, który stał się płodny przez dziesięciolecia. Ale tajemnice dla czytelników nie powinny pozostać. Dlatego dla pokazania zasady działania takich programów strace podam kod miniaturowego trackera - Ślad prosiaka (ptr). Nie wie, jak zrobić nic specjalnego, ale najważniejsze - wywołania systemowe programu - wyświetlają:

$ 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 rozpoznaje około stu wywołań systemowych Linuksa (patrz poniżej). stół) i działa tylko na architekturze x86-64. To wystarczy do celów edukacyjnych.

Przyjrzyjmy się, jak działa nasz klon. W przypadku Linuksa debugery i moduły śledzące korzystają, jak wspomniano powyżej, z wywołania systemowego ptrace. Działa poprzez przekazanie w pierwszym argumencie identyfikatorów poleceń, których tylko potrzebujemy PTRACE_TRACEME, PTRACE_SYSCALL и PTRACE_GETREGS.

Tracer uruchamia się w normalnym stylu uniksowym: fork(2) rozpoczyna proces potomny, który z kolei za pomocą exec(3) uruchamia badany program. Jedyną subtelnością jest tutaj wyzwanie ptrace(PTRACE_TRACEME) przed exec: proces potomny czeka, aż proces nadrzędny go obejrzy:

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");
}

Proces nadrzędny powinien teraz wywołać wait(2) w procesie potomnym, czyli upewnij się, że nastąpiło przełączenie do trybu śledzenia:

/* 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");

To kończy przygotowania i możesz przejść bezpośrednio do śledzenia wywołań systemowych w nieskończonej pętli.

Zadzwoń ptrace(PTRACE_SYSCALL) zapewnia, że ​​następny wait parent zakończy albo przed wykonaniem wywołania systemowego, albo natychmiast po jego zakończeniu. Pomiędzy dwoma wywołaniami możesz wykonać dowolne akcje: zastąpić wywołanie alternatywnym, zmienić argumenty lub zwrócić wartość.

Wystarczy, że wywołamy komendę dwa razy ptrace(PTRACE_GETREGS)aby uzyskać stan rejestru rax przed wywołaniem (numer wywołania systemowego) i bezpośrednio po (wartość zwracana).

Właściwie pętla:

/* 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);
}

To cały tropiciel. Teraz wiesz, od czego zacząć kolejne przeniesienie DTrace na Linuksie.

Podstawy: uruchamianie programu pod strace

Jako pierwszy przypadek użycia straceByć może warto podać najprostszy sposób - uruchomienie działającej aplikacji strace.

Aby nie zagłębiać się w niekończącą się listę wywołań typowego programu, piszemy minimalny program około 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;
}

Zbudujmy program i upewnijmy się, że działa:

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

I na koniec uruchom go pod strace:

$ 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)                           = ?

Bardzo gadatliwy i niezbyt pouczający. Występują tu dwa problemy: dane wyjściowe programu są mieszane z danymi wyjściowymi strace i mnóstwo wywołań systemowych, które nas nie interesują.

Możesz oddzielić standardowy strumień wyjściowy programu od wyjścia błędów śledzenia za pomocą przełącznika -o, który przekierowuje listę wywołań systemowych do pliku argumentów.

Pozostaje uporać się z problemem „dodatkowych” połączeń. Załóżmy, że interesują nas tylko połączenia write. Klucz -e pozwala określić wyrażenia, według których będą filtrowane wywołania systemowe. Najpopularniejszym wariantem warunku jest oczywiście trace=*, dzięki któremu możesz pozostawić tylko interesujące nas połączenia.

Używane jednocześnie -o и -e dostaniemy:

$ 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 +++

Więc widzisz, jest dużo łatwiejszy do odczytania.

Możesz także usunąć wywołania systemowe - na przykład te związane z alokacją i zwolnieniem pamięci:

$ 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 +++

Zwróć uwagę na wykrzyknik ze zmianą znaczenia na liście wykluczonych wywołań: jest to wymagane przez powłokę. powłoka).

W mojej wersji glibc wywołanie systemowe kończy wykonywanie procesu exit_groupzamiast tradycyjnego _exit. Na tym polega trudność pracy z wywołaniami systemowymi: interfejs, z którym współpracuje programista, nie jest bezpośrednio powiązany z wywołaniami systemowymi. Co więcej, zmienia się regularnie w zależności od wdrożenia i platformy.

Podstawy: dołączanie do procesu w locie

Początkowo wywołanie systemowe ptrace, na którym znajduje się plik strace, można użyć tylko podczas uruchamiania programu w trybie specjalnym. Takie ograniczenie mogło wydawać się rozsądne w czasach wersji 6 Uniksa. W dzisiejszych czasach to już nie wystarczy: czasami trzeba zbadać problemy działającego programu. Typowym przykładem jest proces, który jest zablokowany na uchwycie lub śpi. Dlatego nowoczesny strace może dołączać do procesów w locie.

Wiszący przykład программы:

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;
}

Skompilujmy program i upewnijmy się, że się zawiesza:

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

Spróbujmy teraz do tego dołączyć:

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

Program zablokowany przez połączenie pause. Zobaczmy, jak reaguje na sygnały:

$ 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 +++

Uruchomiliśmy zawieszony program i dołączyliśmy do niego strace. Wyszły na jaw dwie rzeczy: wywołanie systemowe pauzy ignoruje sygnały bez procedur obsługi i, co ciekawsze, strace monitoruje nie tylko wywołania systemowe, ale także przychodzące sygnały.

Przykład: śledzenie procesów potomnych

Praca z procesami poprzez połączenie fork jest podstawą wszystkich Uniksów. Zobaczmy jak strace współpracuje z drzewem procesów na przykładzie prostej „hodowli” программы:

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);
}

W tym przypadku proces nadrzędny tworzy proces potomny, który zapisuje na standardowe wyjście:

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

Domyślnie zobaczymy tylko wywołania systemowe procesu nadrzędnego:

$ 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 +++

Flaga pomaga śledzić całe drzewo procesów. -f, Który strace śledzi wywołania systemowe w procesach potomnych. Do każdej linii wyniku dodawany jest pid proces generujący dane wyjściowe systemu:

$ 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 +++

W tym kontekście przydatne może być filtrowanie według grup wywołań systemowych:

$ 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 +++

Swoją drogą, jakie wywołanie systemowe jest używane do tworzenia nowego procesu?

Przykład: ścieżki plików zamiast uchwytów

Znajomość deskryptorów plików jest z pewnością przydatna, ale nazwy konkretnych plików, do których program uzyskuje dostęp, mogą się również przydać.

następny program zapisuje linię do pliku tymczasowego:

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;
}

Podczas normalnego połączenia strace pokaże wartość numeru deskryptora przekazanego do wywołania systemowego:

$ 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 +++

Z flagą -y narzędzie pokazuje ścieżkę do pliku, któremu odpowiada deskryptor:

$ 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 +++

Przykład: śledzenie dostępu do plików

Kolejną przydatną funkcją jest wyświetlanie tylko wywołań systemowych powiązanych z konkretnym plikiem. Następny program dołącza ciąg do dowolnego pliku przekazanego jako 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;
}

Domyślnie strace generuje wiele zbędnych informacji. Flaga -P z argumentem powoduje, że strace wyświetla tylko dostęp do określonego pliku:

$ 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 +++

Przykład: programy wielowątkowe

Użyteczność strace może pomóc podczas pracy z wieloma wątkami program. Poniższy program zapisuje na standardowe wyjście z dwóch strumieni:

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);
}

Należy go oczywiście skompilować ze specjalnym przywitaniem linkera - flagą -pthread:

$ 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
$

Flaga -f, podobnie jak w przypadku normalnych procesów, doda do każdej linii pid procesu.

Oczywiście nie mówimy o identyfikatorze wątku w sensie implementacji standardu POSIX Threads, ale o liczbie używanej przez Linuxowy harmonogram zadań. Z punktu widzenia tego ostatniego nie ma procesów i wątków - są zadania, które trzeba rozdzielić pomiędzy dostępne rdzenie maszyny.

Podczas pracy w wielu wątkach wywołania systemowe stają się zbyt duże:

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

Sensowne jest ograniczenie się do zarządzania procesami i wywołań systemowych 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 +++

Przy okazji, pytania. Jakie wywołanie systemowe jest używane do tworzenia nowego wątku? Czym różni się to wywołanie wątków od wywołania procesów?

Klasa mistrzowska: Stos procesów w czasie wywołania systemowego

Jeden z ostatnich strace możliwości - wyświetlanie stosu wywołań funkcji w momencie wywołania systemowego. Prosty przykład:

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;
}

Naturalnie dane wyjściowe programu stają się bardzo obszerne i oprócz flagi -k (wyświetlając stos wywołań), sensowne jest filtrowanie wywołań systemowych według nazwy:

$ 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 +++

Klasa mistrzowska: wstrzykiwanie błędów

I jeszcze jedna nowa i bardzo przydatna funkcja: wstrzykiwanie błędów. Tutaj program, który zapisuje dwie linie do strumienia wyjściowego:

#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;
}

Śledzenie obu wywołań zapisu:

$ 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 +++

A teraz używamy wyrażenia injectaby wstawić błąd EBADF do wszystkich napiszcie telefony:

$ 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 +++

Ciekawe jakie błędy zwracają wszystko wyzwania write, łącznie z wywołaniem ukrytym za błędem. Zwrócenie błędu tylko dla pierwszego z wywołań ma sens:

$ 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 +++

Lub drugi:

$ 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 +++

Typ błędu jest opcjonalny:

$ 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 +++

W połączeniu z innymi flagami można „przerwać” dostęp do konkretnego pliku. Przykład:

$ 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 +++

Oprócz błędnych zastrzyków, można wprowadzić opóźnienia podczas wykonywania połączeń lub odbierania sygnałów.

Posłowie

Użyteczność strace to proste i niezawodne narzędzie. Ale oprócz wywołań systemowych debugowane są również inne aspekty działania programów i systemu operacyjnego. Na przykład może śledzić wywołania dynamicznie połączonych bibliotek ślad, sprawdź działanie systemu operacyjnego Dotknij systemu и śladi dogłębnie zbadać wydajność programów, na które pozwala perf. Jednak tak jest strace - pierwsza linia obrony w przypadku problemów z programami własnymi i cudzymi i korzystam z niej przynajmniej kilka razy w tygodniu.

Krótko mówiąc, kochaj Uniksa, czytaj man 1 strace i nie krępuj się szpiegować swoich programów!

Źródło: www.habr.com

Dodaj komentarz