Debug – hibakeresés, bináris debug, kis lépések módszere, strace

Ha programozunk, debug-olnuk is kell, azaz hibát is kell keresnünk, mivel a hibátlan programozást még nem találták fel. Erre komplett fejlesztő eszközök vannak, melyek használatát itt nem részletezném. Maga a debug szó “bogártalanítást” jelent, és egy urbánus legendába hajló sztori az alapja. Az első számítógépek fizikai relékkel (jelfogókkal) működtek. Egy ilyen őskori gép egyszer elromlott, mivel bele ment egy bogár. 🙂 Azóta debug a hibakeresés.

Nézzük a programozó alap és egyben legvégső fegyverét, a bináris debug-ot. Ehhez binárisan kell gondolkodnunk. Működési elve igen egyszerű.

1. Felezzük meg a kódunkat, kommentezzük ki a kód egyik felét.
2. Ha megtaláljuk a hibát az egyik felében, és nem értünk a végére, akkor 1-es lépés (felezzük tovább a kódot). Ha a végére értünk, akkor megvan a hiba. 🙂
3. Ha nincs benne hiba, akkor cseréljük fel a kikommentezett felet és a nem kikommentezett felet, majd 1-es lépés. 🙂

Látható, hogy nem bonyolult, legfeljebb időigényes. Hamar be lehet a segítségével korlátozni a hiba helyét egy-két sornyi kódra. A lépések száma a kettő hatványainak kitevője, ebben a matematikai mélységi kereséshez hasonlít. Ezzel a módszerrel még akkor is boldogulunk, ha több hiba is előfordul a kódban, mivel “brute force” az algoritmus. 🙂

Ja és hogy mit jelent a “kikommentezés”? Olyan kódrészlet, ami nem hajtódik végre, kisegítő információ a forráskódban a programozók számára (a forráskód általában lefordításra kerül, hogy a számítógép is “megértse”). Ahogy az eddigiekben látható, shell script-ben a hashmark # a sor elején vagy végén a megjegyés helye, C-ben, C++-ban és JAVA-ban pedig a blokk megjegyzés /* megjegyzés */ formátumú, illetve az egy sornyi megjegyés a // jelek után írandó.

A kis lépések módszere még egyszerűbb az előbbinél, és széles körűen alkalmazzák a fejlesztők. A lényege, hogy csak egy vagy legfeljebb pár sor új kódot adunk hozzá az addigiekhez programozás során, illetve csak egy újabb modult fűzünk hozzá, nem egyből egy maréknyit, és természetesen egyből tesztelünk. Így gyorsan kiderül, ha hibás kódot írtunk le, és nem kell három napot egyetlen hiba megtalálásával töltenünk! 🙂

Végül nézzük meg a strace használatát (miután apt-get-tel telepítettem). Ezzel a programmal a rendszerhívásokat és a jelzéseket írathatjuk ki egy tetszőleges program végrehajtása során. Vegyük az egyszerű alma.sh programot.

gvamosi@gergo1:~$ cat alma.sh
#!/bin/sh
ls --color -l

Meglepő lehet, de a kétsoros script hatalmas strace kimenetet generál! Nézzük meg a “nyomkövetés” eredményét.

gvamosi@gergo1:~$ strace alma.sh
execve("./alma.sh", ["alma.sh"], 0x7fffb90cb390 /* 39 vars */) = 0
brk(NULL) = 0x55ffa24e5000
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=169286, …}) = 0
mmap(NULL, 169286, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f458d3ff000
close(3) = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\260A\2\0\0\0\0\0"…, 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1824496, …}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f458d3fd000
mmap(NULL, 1837056, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f458d23c000
mprotect(0x7f458d25e000, 1658880, PROT_NONE) = 0
mmap(0x7f458d25e000, 1343488, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x22000) = 0x7f458d25e000
mmap(0x7f458d3a6000, 311296, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x16a000) = 0x7f458d3a6000
mmap(0x7f458d3f3000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1b6000) = 0x7f458d3f3000
mmap(0x7f458d3f9000, 14336, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f458d3f9000
close(3) = 0
arch_prctl(ARCH_SET_FS, 0x7f458d3fe580) = 0
mprotect(0x7f458d3f3000, 16384, PROT_READ) = 0
mprotect(0x55ffa169d000, 8192, PROT_READ) = 0
mprotect(0x7f458d450000, 4096, PROT_READ) = 0
munmap(0x7f458d3ff000, 169286) = 0
getuid() = 1000
getgid() = 1000
getpid() = 19358
rt_sigaction(SIGCHLD, {sa_handler=0x55ffa1693380, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER, sa_restorer=0x7f458d273840}, NULL, 8) = 0
geteuid() = 1000
brk(NULL) = 0x55ffa24e5000
brk(0x55ffa2506000) = 0x55ffa2506000
getppid() = 19355
stat("/home/gvamosi", {st_mode=S_IFDIR|0755, st_size=4096, …}) = 0
stat(".", {st_mode=S_IFDIR|0755, st_size=4096, …}) = 0
openat(AT_FDCWD, "./alma.sh", O_RDONLY) = 3
fcntl(3, F_DUPFD, 10) = 10
close(3) = 0
fcntl(10, F_SETFD, FD_CLOEXEC) = 0
geteuid() = 1000
getegid() = 1000
rt_sigaction(SIGINT, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGINT, {sa_handler=0x55ffa1693380, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER, sa_restorer=0x7f458d273840}, NULL, 8) = 0
rt_sigaction(SIGQUIT, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGQUIT, {sa_handler=SIG_DFL, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER, sa_restorer=0x7f458d273840}, NULL, 8) = 0
rt_sigaction(SIGTERM, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGTERM, {sa_handler=SIG_DFL, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER, sa_restorer=0x7f458d273840}, NULL, 8) = 0
read(10, "#!/bin/sh\n\nls --color -l\n", 8192) = 25
stat("/usr/local/bin/ls", 0x7ffea163b940) = -1 ENOENT (No such file or directory)
stat("/usr/bin/ls", 0x7ffea163b940) = -1 ENOENT (No such file or directory)
stat("/bin/ls", {st_mode=S_IFREG|0755, st_size=138856, …}) = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f458d3fe850) = 19359
wait4(-1, total 300
lrwxrwxrwx 1 gvamosi gvamosi 5 Sep 8 11:18 alma.sh -> ls.sh
..
-rwxr-xr-x 1 gvamosi gvamosi 25 Sep 8 11:10 ls.sh
..
drwxr-xr-x 2 gvamosi gvamosi 4096 Aug 26 2017 Videos
[{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 19359
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=19359, si_uid=1000, si_status=0, si_utime=0, si_stime=0} ---
rt_sigreturn({mask=[]}) = 19359
read(10, "", 8192) = 0
exit_group(0) = ?
+++ exited with 0 +++

Használjuk csak valamire ezt a kimenetet! Látható, hogy az ls parancsot a keresési útvonalban két helyen is “hiába” keresi a programunk. Nézzük meg a which paranccsal, hogy hol található az ls parancs.

gvamosi@gergo1:~$ which ls
/bin/ls

Javítsuk ki a scriptben a dolgot, írjuk bele a teljes útvonalat! Most nézzük csak meg a releváns strace kimeneti részt!

rt_sigaction(SIGTERM, {sa_handler=SIG_DFL, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER, sa_restorer=0x7f52fb075840}, NULL, 8) = 0
read(10, "#!/bin/sh\n\n/bin/ls --color -l\n", 8192) = 30
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f52fb200850) = 13884
wait4(-1, total 300

Nincs is stat hívás az ls-re. Optimalizáltuk a kódot; három rendszerhívással kevesebb. Voila! 🙂

Végezetül köszönettel tartozom JÁ barátomnak a bináris debug-ért, hogy egyszer régen megtanított rá, illetve ide idézem FCs barátom jó tanácsát programozóknak, szintén köszönettel: “Programozni jól, és hibátlanul kell!” 🙂