Strace programos diegimas ir panaudos atvejai

iv_vytenisg

Kartais programa pradeda elgtis nekorektiškai. Pavyzdžiui būna pateikiama neteisinga įvestis ir nebepateikiama išvestis, ji nieko nepateikia arba net pakimba. Pagal Linux pagrįstą sistemą kiekvienas vartotojo srities procesas turi sąveikauti su savo aplinka per serverio branduolį. Tai daroma pasinaudodamas sisteminiais susijungimais (angl. syscall).

strace - programinė įranga skirta stebėti ir daryti įtaką virtualiai dedikuoto serverio bei jo branduolio tarpusavio komunikacijai t.y. sisteminiai susijungimai, signalo siuntimai ir procesų būsenų keitimas. Šis įrankis yra neįkainojamas sistemos administratoriams, nes padeda spręsti problemas, susijusias su programomis, kurių šaltinis nėra lengvai skaitomas, kadangi jie neturi būti perkompliuojami siekiant juos atsekti. Šiam veiksmų atlikimui strace pasitelkia branduolio funkciją ptrace.

0. Preliminarūs reikalavimai

Linux virtualiai dedikuotas serveris naudojantis Ubuntu operacinės sistemos šabloną.

1. strace diegimas

strace diegimas atliekamas terminale įvykdžius šią komandą:

apt-get install strace

2. Bendras susijungimų stebėjimas

Norėdami pamatyti visus strace fiksuojamus išrašus paleiskite šią komandą:

strace ls

Pateikiamas atsakymas:

execve("/usr/bin/ls", ["ls"], 0x7ffcbe758420 /* 32 vars */) = 0
brk(NULL)                               = 0x55f96664b000
arch_prctl(0x3001 /* ARCH_??? */, 0x7ffdf617fd20) = -1 EINVAL (Invalid argument)
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=23464, ...}) = 0
mmap(NULL, 23464, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f67f037a000
close(3)                                = 0
<...>

3. Filtravimas pagal instrukcijų kodus

Kaip matote aukščiau, strace išrašas yra sudėtingai skaitomas, todėl reikia įvesti papildomus parametrus reikiamų išrašų filtravimui. Kaip pavydžiui -i parametras išrikiuos išrašus pagal instrukcijų žymas. Naudojama komanda:

strace -i ls

Pateikiamo atsakymo pavyzdys:

[00007fd83fe6d16b] execve("/usr/bin/ls", ["ls"], 0x7fffb24a3848 /* 32 vars */) = 0
[00007fca9ed92eab] brk(NULL)            = 0x5613e656b000
[00007fca9ed91b55] arch_prctl(0x3001 /* ARCH_??? */, 0x7ffcbfeda780) = -1 EINVAL (Invalid argument)
[00007fca9ed93d5b] access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
[00007fca9ed93ec8] openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
[00007fca9ed93c99] fstat(3, {st_mode=S_IFREG|0644, st_size=23464, ...}) = 0
[00007fca9ed940e6] mmap(NULL, 23464, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fca9ed6f000
[00007fca9ed93d8b] close(3)             = 0
<...>

4. Filtravimas pagal laiko žymę

Taip pat galite filtruoti sistemos užklausas pagal laiko žymę rodančią laiko skirtumą tarp sėkmingai įvykdytų sistemos užklausų. Šiam filtravimui naudojamas parametras -r. Įvykdykite komandą terminale:

strace -r ls

Pateikiamo atsakymo pavyzdys:

 0.000000 execve("/usr/bin/ls", ["ls"], 0x7ffc4adec758 /* 32 vars */) = 0
     0.001397 brk(NULL)                 = 0x55c1e8c8f000
     0.000440 arch_prctl(0x3001 /* ARCH_??? */, 0x7ffeb2f728c0) = -1 EINVAL (Invalid argument)
     0.000674 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
     0.000461 openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
     0.000377 fstat(3, {st_mode=S_IFREG|0644, st_size=23464, ...}) = 0
     0.000672 mmap(NULL, 23464, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f22f11ed000
     0.000280 close(3)                  = 0
<...>

5. Filtravimas pagal laiką

Jeigu norite, kad visi įrašai būtu pateikiami pagal įvykdymo laiką, galite naudoti parametrą -t:

strace -t ls

Pateikiamo atsakymo pavyzdys:

09:54:45 execve("/usr/bin/ls", ["ls"], 0x7ffe7311fc08 /* 32 vars */) = 0
09:54:45 brk(NULL)                      = 0x564b5aa76000
09:54:45 arch_prctl(0x3001 /* ARCH_??? */, 0x7fff64661a40) = -1 EINVAL (Invalid argument)
09:54:45 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
09:54:45 openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
09:54:45 fstat(3, {st_mode=S_IFREG|0644, st_size=23464, ...}) = 0
09:54:45 mmap(NULL, 23464, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f837a0cb000
09:54:45 close(3)                       = 0
<...>

Taip yra papildomi du parametrai filtravimui pagal laiką:

* -tt - jeigu nurodysite dvi t raides, laikas bus pateikiamas su mikrosekundėmis.

* -ttt - jeigu nurodysite tris t raides, laikas bus pateikiamas su mikrosekundėmis bei pagrindinė dalis bus pateikta kaip sekundžių skaičius nuo epochos.

6. Laiko, sugaišto sistemos užklausoje, pateikimas

Norint pamatyti kiek laiko buvo sugaišta vykdant užklausą, galite naudoti -T parametą

strace -T ls

Pateikiamo atsakymo pavyzdys:

execve("/usr/bin/ls", ["ls"], 0x7ffc75cf3388 /* 32 vars */) = 0 <0.000906>
brk(NULL)                               = 0x56134ea3f000 <0.000288>
arch_prctl(0x3001 /* ARCH_??? */, 0x7ffc7c86c780) = -1 EINVAL (Invalid argument) <0.000324>
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory) <0.000312>
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 <0.000263>
fstat(3, {st_mode=S_IFREG|0644, st_size=23464, ...}) = 0 <0.000105>
mmap(NULL, 23464, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f0f8c5cc000 <0.000123>
close(3)                                = 0 <0.000086>

Paryškintos reikšmės yra sugaištas syscall laikas.

7. Apibendrintos informacijos pateikimas

Norint matyti apibendrinimą visų užklausų turite naudoti -c parametrą:

strace -c ls

Pateikiamo rezultato pavyzdys:

post_install.log  snap
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 34.42    0.000221         110         2           ioctl
 16.67    0.000107          15         7           read
 11.68    0.000075           6        11           close
 11.21    0.000072           8         9           openat
  8.41    0.000054           5        10           fstat
  7.63    0.000049          24         2           getdents64
  3.74    0.000024          24         1           write
  3.27    0.000021           0        27           mmap
  2.96    0.000019           9         2         2 access
  0.00    0.000000           0         9           mprotect
  0.00    0.000000           0         1           munmap
  0.00    0.000000           0         3           brk
  0.00    0.000000           0         2           rt_sigaction
  0.00    0.000000           0         1           rt_sigprocmask
  0.00    0.000000           0         8           pread64
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         2         2 statfs
  0.00    0.000000           0         2         1 arch_prctl
  0.00    0.000000           0         1           set_tid_address
  0.00    0.000000           0         1           set_robust_list
  0.00    0.000000           0         1           prlimit64

Šioje lentelėje galite matyti apibendrinimą, kiek užklausų buvo atlikta per syscall bei informaciją apie tai kiek laiko jos truko.

8. Konkrečių užklausų suradimas

Norint surasti užklausą pagal tipą, galite naudoti šią komandą:

strace -e trace=write ls

Reikšmė white konkrečiu atveju ieško procesų, kurių metu buvo vykdomas informacijos rašymas.

Pateikiamo rezultato pavyzdys:

write(1, "post_install.log  snap\n", 23post_install.log  snap
) = 23
+++ exited with 0 +++

Kaip pastebite, atsakyme yra pateikiamas užklausos pavadinimas, argumentas ir rezultatas.

9. Programos aktyvavimas kartu su strace stebėjimo iniciavimu ir išrašo

Pridėti atskirą programą su išrašo sukūrimu atskirame faile galite įvykdę komandą:

strace -Ff -tt <programa> <užklausos-tipas> 2>&1 | tee strace-<programa>.log

Stebėjimo veiksmas bus pradėtas. Dabar galite atlikti veiksmus, po kurių pastebėjote programos nekorektišką veikimą. Atlikus veiksmus galite peržiūrėti strace programos rodomus išrašus faile strace-programa.log

10. Naudojimas su šiuo metu veikiančiose programose

Tikėtina, kad norėsite įjungti strace išrašą tik tam tiktu atitinkamu metu. Tai būna naudinga tais atvejais kai išrašę randate tokį didelį kiekį įrašu, kad tampa sunku atsekti kur konkrečiai gali būti problema. Arba norite nustatyti, ką veikia programa tuo metu kai užstringa.

Susiraskite proceso ID su komanda:

pidof <programa>

 

Pirdėkite procesą prie strace stebimų programų:

strace -p <PID>

Arba aktyvuokite strace fiksavimą su konkrečių proceso numeriu bei tuo pačiu generuojamu išrašu:

strace -Ff -tt -p <PID> 2>&1 | tee strace-<programa>.log

Tada atlikite reikiamus veiksmus problemos pašalinimui. Gali būti, kad turėsite panaudoti Ctrl+C komandą tam, kad atjungtumėte strace nuo veikiančios programos. Užbaigę veiksmus galite peržiūrėti ką fiksavo strace faile strace-<programa>.log išrašas.

Daugiau informacijos apie galimas panaudojimo galimybes arba skirtingus syscall tipus, rasite oficialiame strace puslapy.