Jedna z často zmiňovaných předností unix systémů je rozsáhla sada nástroju pro diagnostiku, debug, za to velký, ale opravdu velký dík.
Jedním z těchto nástrojů je také strace. Strace monitoruje systémová volání a signály pomocí speciálního syscallu ptrace, který slouží pro trasování bežícího kódu programu, ptrace je rozsahlá a velmi silná záležitost, dokaže se napojit na proces, krokovat ho, zasahovat do jeho paměti, odchýtávat signály apod, je také výužíváno oblíbeným GNU debugerem gdb.
(Pozn.: ptrace na první pohled vypadá jako pěkná bezpečnostní díra díky možnosti kontroly na jiným procesem, typicky je proto toto volání umožněho pouze potomkům procesu nebo speciálně pro Linux řízení pomocí capabilities SYS_PTRACE, toto ovšem neplatí pro roota)
Pokud netušíte co nebo k čemu jsou systémová volání a signály netrapte se, dejte si pořádný pohár jahodové zmrzliny se šlehačkou a hoďte to za hlavu nebo se můžete podívat např. do knihy Jádro systému Linux od Lukáše Jelínka.
Systémová volání (system call, syscall) představuji v informatice mechanismu komunikace programu s jádrem operačního systému, program po dobu svého životního cyklu buď volá funkce systému nebo si něco počítá. Příkladem takového volání je např. sys_open pro otevření souboru nebo sys_read resp. sys_write pro čtení resp. zápis do deskriptoru (rozuměj souboru). Syscallů je značné množství, přesto je snaha udržet jejich počet na rozumném počtu, překotný vývoj a implementace byl pro např. Linux ve verzích 1.x, 2.x, ze své povahy jde o relativně stabilní část jádra. http://man7.org/linux/man-pages/man2/syscalls.2.html Velmi pěkný článek o syscall na IBM Developer. https://www.ibm.com/developerworks/linux/library/l-system-calls/
Signály představují jeden z nástroju meziprocesové komunikace, obecně se celá tato oblast označuje jako IPC(Inter-Process Communication), jde o formu výměny jednoduchých zpráv, pokud je procesu zaslán signál, operační systém přeruší jeho výkonávání (pozn. nechytáme se za slovo, k přeřušení může dojít pouze během NE-atomické operace) a zavolá se obsluha (handler, rutina) signálu, pokud vše "dobře" dopadne systém vrátí zpět řízení a původní proces běží dál.
Strace prakticky malá ukázka, zkusme si představit malý program bez dostupnosti zdrojového kódu, říkejme mu pwd (ano pwd součastí coreutils, ale to není podstatné), pustíme na něj strace.
root@havel-machine:/tmp/strace# strace pwd
execve("/bin/pwd", ["pwd"], [/* 23 vars */]) = 0
brk(0) = 0xb3d000
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f2b2b01e000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
...
...
...
getcwd("/tmp/strace", 4096) = 12
fstat(1, {st_mode=S_IFCHR|0600, st_rdev=makedev(136, 11), ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f2b2b01d000
write(1, "/tmp/strace\n", 12/tmp/strace
) = 12
close(1) = 0
munmap(0x7f2b2b01d000, 4096) = 0
close(2) = 0
exit_group(0) = ?
+++ exited with 0 +++
Výstup jsem zkrátil, ale v jednoduchosti, na levé straně vidíme použitá systémová volání na pravé pak jejich návratové hodnoty (číslo za =), co vidíme na první řádce sámotné spuštění programu pwd (za nás to udělal shell) pomocí syscall execve, následuje volání brk bez parametrů vrací aktuální hodnotu datového segmentu a pak tanečky kolem oprávnění, LD_PRELOAD a dynamického linkeru, až téměr na konci je zavoláno systémové volání getpwd vracející jako návratovou hodnotu aktuální pracovní adresář (ano, na to je také syscall), následuje vypsání této hodnoty na terminál pomocí opět systémového volání write (povšimněte si hodnoty 1 u volání write, jako první argument této funkce je tzv. číslo deskriptoru kam se bude zapisovat, hodnotu 1 reprezentuje v unix světe tzv. stdout [standartní výstup], 0 = stdin [standartní vstup], 2 = [standartní chybový výstup], takže vlastně výpis dat na terminál není nic jiného než zápis do soubor, skvělé že).
Pěkné co to umí dál? Mohou se občas hodit jen statistické údaje.
root@havel-machine:/tmp/strace# strace -c pwd /tmp/strace % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 24.36 0.000104 12 9 mmap 14.75 0.000063 21 3 3 access 11.48 0.000049 12 4 mprotect 11.24 0.000048 16 3 open 9.13 0.000039 20 2 munmap 8.43 0.000036 7 5 close 6.56 0.000028 7 4 fstat 5.15 0.000022 22 1 write 2.34 0.000010 3 3 brk 2.34 0.000010 10 1 execve 1.87 0.000008 8 1 read 1.41 0.000006 6 1 getcwd 0.94 0.000004 4 1 arch_prctl ------ ----------- ----------- --------- --------- ---------------- 100.00 0.000427 38 3 total
Další užitečnost, filtrování pouze specifických volání nebo skupin (skupiny určíte -e trace=skupiny, např. -e trace=file,network,process, viz man strace)
root@havel-machine:/tmp/strace# strace -e open,write pwd
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
open("/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
open("/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3
write(1, "/tmp/strace\n", 12/tmp/strace
) = 12
+++ exited with 0 +++
Napojení se na běžící proces je jedna z dalších užitečných vlastností, v praxi lze narazit na situaci, kdy program buď nedělá co má (čéka na něco) nebo naopak něco dělá a dělá to tak rychle jak dokáže (typicky vytěžuje jedno celé jádro systému), chceme většinou zjistit co se děje.
root@havel-machine:/tmp/strace# strace -c -p 3117 Process 3117 attached Process 3117 detached % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 47.67 0.000143 2 80 78 recvmsg 47.00 0.000141 4 40 poll 3.00 0.000009 5 2 writev 2.33 0.000007 7 1 restart_syscall ------ ----------- ----------- --------- --------- ---------------- 100.00 0.000300 123 78 total
Parametrem (-p PID) jsme se připojili k běžícímu procesu, v tomto případě komunikátor pro IM, zajímá nás pouze statistika, vídíme, že proces neustále “polluje” deskriptor (v tomto případě síťový soket, ale opět je chování velmi podobné souboru) a přijímá zprávy ze socketu přes volání recvmsg, opět je možné si detailně zobrazit volání a přidat např. timestamp (-t), čítač instrukcí (-i) nebo filtrovat pomocí (-e) kategorie volání.
Toto chování s napojením na běžící proces je velmi užitečné, v případě zaseknutí procesu např. při otevírání souboru uvidíme jeho snadu o přístup, lze si tedy udělat představu co program očekává a případně mu trochu pomoci.
!!! Pozor !!! Používání strace sebou nese značný výkonový overhead (penalizaci v podobě rychlosti vykonávání trasovaného programu), pro představu v ukázce použitý nástroj pwd se při trasování zpomalil ~ 10x, úplným extrémem trasování nástroje dd při dd if=/dev/zero of=/dev/null došlo k jeho zpolení více než 200x., intenzivní I/O operace jsou penalizovány razantně, dejte na to pozor.
Blížíme se k samotnému závěru, jak bylo v úvodu řečeno, unix (linux) disponuje značným množstvím diagnostických nástroju, je důležité používat spravným nástroj na správnou část jádra, následující obrázek pěkně ilustruje co a kde by mohlo Vám pomoci.
Viditelnost strace je především pro systémová volání.
Zazvonil zvonec a debugu je konec, a tahle funguje strace, díky tomu, že porozumíte jaká systémová volání používá proces jste schopní odhadnout jak a proč se chová.
Až budete zase na něco v terminálu zdlouhavě čekat vzpomeňte si na strace, mimochodem teď už Vás asi nepřekvapí, že volání sleep je také samozdřejme syscall.
Pro fajnšmekry ukázka co se dá realitovat s ptrace volání, program retty od Petra Baudiše, aneb jak se dostat v terminálu programu (mutt) když jsem zapomělo pustit screen, slušný hack, nicméně asi již nefunkční, ale i tak respekt.
Abych nezapoměl man strace je jako vždy dobrý pomocník.
Děkuji za Váš čas. František Havel
