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 perkompiliuojami siekiant juos atsekti. Šiam veiksmų atlikimui strace pasitelkia branduolio funkciją ptrace.
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 pavyzdž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 parametrą
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 inicijavimu 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>
Pridė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 puslapyje.