Ladění a odvšivování C
Obecné nástroje
ps
ps axjf | less
PPID PID PGID SID TTY TPGID STAT UID TIME COMMAND
12052 12540 12540 12540 ? -1 Ss 0 0:00 \_ sshd: flowmon [priv]
12540 12542 12540 12540 ? -1 S 500 0:03 | \_ sshd: flowmon@pts/0
12542 12543 12543 12543 pts/0 24512 Ss 500 0:00 | \_ -bash
12543 24511 24511 12543 pts/0 24512 S 0 0:00 | \_ su
24511 24512 24512 12543 pts/0 24512 S+ 0 0:00 | \_ bash
ps -eFL | grep "/bin/some"
UID PID PPID LWP C NLWP SZ RSS PSR STIME TTY TIME CMD
503 26207 10278 26207 11 4 1455062 4857636 6 Nov15 ? 13:28:28 /bin/something
503 26207 10278 26207 11 4 1455062 4857636 6 Nov15 ? 13:28:28 /bin/something
503 26207 10278 26768 0 4 1455062 4857636 1 Nov15 ? 00:00:00 /bin/something
503 26207 10278 1849 0 4 1455062 4857636 1 Nov18 ? 00:00:00 /bin/something
503 26207 10278 1850 0 4 1455062 4857636 3 Nov18 ? 00:00:00 /bin/something
start time - datum/čas spuštění procesu. V kombinaci s time nám říka, jak proces dlouho běží a jak moc využívá procesor. Například následující výpis říká, že procesy postgress byly spuštěny 1.12.2013 a na procesoru běžely necelé dvě minuty (přestože teď je už 2.12 9:30). Procesy tedy skoro nic nedělají.
ps -ef | grep postgress
UID PID PPID C STIME TTY TIME CMD
postgres 7534 4669 0 Dec01 ? 00:01:04 postgres: somebody somebody 127.0.0.1(37573) VACUUM
postgres 13828 4669 0 Dec01 ? 00:01:28 postgres: somebody somebody 127.0.0.1(35066) VACUUM
postgres 14167 4669 0 Dec01 ? 00:01:11 postgres: somebody somebody 127.0.0.1(60953) VACUUM
postgres 16436 4669 0 Dec01 ? 00:01:19 postgres: somebody somebody 127.0.0.1(58098) VACUUM
ps ax | grep postgress
PID TTY STAT TIME COMMAND
7534 ? D 1:04 postgres: somebody somebody 127.0.0.1(37573) VACUUM
13828 ? D 1:28 postgres: somebody somebody 127.0.0.1(35066) VACUUM
14167 ? D 1:12 postgres: somebody somebody 127.0.0.1(60953) VACUUM
16436 ? D 1:19 postgres: somebody somebody 127.0.0.1(58098) VACUUM
17723 ? D 1:07 postgres: somebody somebody 127.0.0.1(47033) VACUUM
top
spotřeba CPU, paměti, …
pomoci klavesy f lze zapnout/vypnout ruzne sloupecky s info o procesu, napriklad swap
pomoci < > lze provest trideni podle sloupcu (reverzni trideni R)
pomoci H lze zapnout zobrazovani threadu
pomoci 1 lze zapnout vypis vsech CPU jader:
sloupec %wa je velice dulezity, jde o I/O waiting. Pokud je I/O waiting skoro 100%, tak je system zatizen (nepouzitelny), i kdyz ma CPU %us velice male.
top - 18:20:11 up 83 days, 10:59, 1 user, load average: 0.06, 0.10, 0.09
Tasks: 137 total, 2 running, 135 sleeping, 0 stopped, 0 zombie
Cpu0 : 5.1%us, 1.0%sy, 0.0%ni, 92.5%id, 1.0%wa, 0.0%hi, 0.3%si, 0.0%st
Cpu1 : 5.2%us, 0.9%sy, 0.0%ni, 93.1%id, 0.7%wa, 0.0%hi, 0.0%si, 0.0%st
CPU load je specialni hodnota, ktera rika, jak jsou CPU procesory/jadra vyuzivany
info.
vypis pameti rika:
pamet celkem (mem total), kolik je ji pouzito (Mem used), kolik je volne (Mem free),
jak velky je swap (Swap total), kolik ze swapu se pouziva (Swap used), kolik je swapu volneho (Swap free) - swap se casto pouziva i pro uvolneni bloku hlavni pameti, ktere se dlouho nepouzivaly. Nemusi jit tedy o nedostatek hlavni pameti.
kolik se pouziva jako file system diskova cache (cached) - to je pamet, kterou lze v pripade potreby uvolnit. Je zahrnuta take v Mem used.
Mem: 2059524k total, 1823764k used, 235760k free, 212016k buffers
Swap: 1028312k total, 90556k used, 937756k free, 1218500k cached
vypis procesu dale rika:
VIRT - veskera pamet adresovana procesem. Kod, data, sdilene knihovny, swap, … . Muze byt vetsi nez je fyzicka pamet. Zapocitava se sem totiz i napriklad adresovani velkych souboru ulozenych ve skutecnosti pouze na disku.
RES - skutecne spotrebovana pamet. RES = CODE + DATA. %MEM = RES/TOTAL.
SHR - sdilena pamet, procesy casto sdili pamet.
TIME - kolik procesoroveho casu proces spotreboval. Vetsinou je nizsi nez doba behu programu (program nema pridelen CPU porad)
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
16069 somebody 20 0 1385m 95m 60m S 10,0 1,2 2:08.56 vlc
22567 somebody 20 0 1889m 274m 97m S 8,3 3,5 131:34.02 gnome-shell
22291 somebody 20 0 324m 129m 58m S 5,7 1,6 71:22.25 Xorg
5685 somebody 20 0 642m 9m 5764 S 3,7 0,1 107:27.06 pulseaudio
lsof
zobrazí file deskriptory (soubory, sockety, pipe), které má proces aktuálně otevřené
seznam obsahuje rovněž spuštěnou binárku a všechny knihovny
dále zde lze zjistit pracovní adresář
u souborů lze zjistit, jaký je aktuální seek
příklad:
pracovní adresář je /home/flowmon/commleak
předchozí adresář je /
binárka je /bin/bash
stdin (0), stdout (1) i stderr (2) je navěšen na terminál /dev/pts0
lsof -p 16901
COMMAND PID USER FD TYPE DEVICE SIZE NODE NAME
bash 16901 root cwd DIR 8,3 4096 464983 /home/flowmon/commleak
bash 16901 root rtd DIR 8,3 4096 2 /
bash 16901 root txt REG 8,3 801816 48121 /bin/bash
bash 16901 root mem REG 8,3 144776 547197 /lib64/ld-2.5.so
..
bash 16901 root 0u CHR 136,0 3 /dev/pts/0
bash 16901 root 1u CHR 136,0 3 /dev/pts/0
bash 16901 root 2u CHR 136,0 3 /dev/pts/0
strace
Nástroj na monitorování systémových volání
Umožňuje zobrazit, co program dělá (pouze systémová volání). Typicky zde jde vidět zda čeká na nějaké I/O, zda na nečem necyklí, zda nečeká na nějký zámek, …
Vypisuje vždy systémové volání s argumenty a návratovou hodnotou. Například u operace write je prvním argumentem file deskriptor. File deskriptory je pak možné dohledat přes lsof -p <pid> (fd 1 je typicky stdinout, fd2 je typicky stderr)
výpis strace je zkrácený na 32 znaků, pokud je potřeba vidět víc, je třeba nastavit větší délku přes strace -s <newlength>
užitečné volby
-tt detailed timestamps
-f also strace any child processes
-v be very verbose, even with common structures
-o write output to file
-s N capture up to N characters of strings, rather than abbreviating with …
gdb
umoňuje se navěsit i na běžící proces
vypíše aktuální instrukci, hodnoty paměti, ..
výpis backtrace, krokování
-
gcore
pmap
time
real 2m4.884s
user 0m52.677s
sys 0m2.528
pokud real < user, tak proces využívá paralelismus
(real - (user+sys)) odpovídá I/O waiting (u single thread procesu)
Diagnostika neoprávněného přístupu do paměti
V céčku jsou nejoblibenější chyby typu segmentation fault. Objevují se totiž náhodně, hlavně když si programátor myslí, že už to má určitě dobře
Nástroje
valgrind
program pro hledání chyb v programu - špatná práce s pamětí.
dokáže dobře detekovat chyby v přístupu mimo alokovanou paměť
je pomalý, u komplikovanějšího kódu mrzne.
má několik rozšíření, například callgrind (vypisuje volání… grafické rozšíření kcachegrind)
address sanitizer
zpomaluje program méně a umí hledat víc chyb než valgrind
podpora v gcc od verze 4.8
podpora v clang od verze 3.3.
Google's tcmalloc heapprofiler
PPROF_PATH=/usr/local/bin/pprof HEAPCHECK=normal HEAPPROFILE=/tmp/heapprof7 /data/xx_memtest
Starting tracking the heap
WARNING: Perftools heap leak checker is active -- Performance may suffer
Dumping heap profile to /tmp/heapprof7.0001.heap (476 MB currently in use)
Dumping heap profile to /tmp/heapprof7.0002.heap (667 MB currently in use)
Have memory regions w/o callers: might report false leaks
Leak check _main_ detected leaks of 600000000 bytes in 2 objects
The 2 largest leaks:
Using local file /data/xx_memtest.
Leak of 500000000 bytes in 1 objects allocated from:
@ 4005ea main
@ 3a0001d9f4 __libc_start_main
@ 400529 _start
Leak of 100000000 bytes in 1 objects allocated from:
@ 40061c main
@ 3a0001d9f4 __libc_start_main
@ 400529 _start
profilování paměti
proces je zpomalen, naměřil jsem cca 14x (dříve to zvládlo zapsat 2.4M flow, při profilování 0.17M)
snapshoty se ukládají v pravidelných intervalech (default, po alokaci zhruba 1
GB) do zvoleného adresáře
snapshoty jsou v interním formátu, programem pprof lze převést do svg, postscript, callgrind formátu
export do postscript nebo svg vyžaduje nějaké desktopové knihovny/binárky, nezkoušel jsem
export do callgrind je super, lze otevřít v kcachegrind
jde zde vidět kdo jakou funkci zavolal a kolik má daná funkce aktuálně alokováno paměti ve snapshotu
například: když vyberu funkci main, tak vidím jaké jiné funkce (alokující nějakou paměť) se z main zavolaly (callee) a kolik každá alokovala. Postup lze opakovat vybráním nějaké ze zavolaných funkcí. Krásně se to analyzuje.
pprof vyžaduje cestu k binárce a snaphostu
je žádoucí, aby binárka byla zkompilována s ladícími symboly (přepínač -g)
místo binárky lze použít i samotné debug symboly ze souboru binárka.debug
$ HEAPPROFILE=/data/ads/tmp/ads-nf-loader.memprof LD_PRELOAD=/data/ads/tmp/bari-memprof/libtcmalloc.so.4.2.6 ads-nf-loader
$ pprof --text /usr/lib/debug/usr/local/bin/ads-nf-loader.debug /data/ads/tmp/ads-nf-loader.memprof.0085.heap
Using local file /usr/lib/debug/usr/local/bin/ads-nf-loader.debug.
Using local file /data/ads/tmp/ads-nf-loader.memprof.0085.heap.
Total: 673.8 MB
572.2 84.9% 84.9% 572.2 84.9% InitCacheBuff
48.5 7.2% 92.1% 48.5 7.2% mainsub
26.4 3.9% 96.0% 26.4 3.9% tpxmit
20.0 3.0% 99.0% 20.0 3.0% NewFile
5.0 0.7% 99.8% 5.0 0.7% LZO_initialize
0.9 0.1% 99.9% 0.9 0.1% SQLAllocEnv
0.4 0.1% 100.0% 0.4 0.1% Insert_Extension_Map
..
Heaptrack
mtrace
Memory not freed:
-----------------
Address Size Caller
0x0000000001b75460 0x4 at /home/bari/Plocha/heaptest/mtrace/badcode-mtrace.c:10
memprof
gdb-heap
zní to pěkně, ale nikdy se mi to nepodařilo úplně rozběhnout
věčně nějaké nepochopitelné python syntax errors
-
Dmalloc
vlastní nástroj
LD_PRELOAD
Backtrace