Unterschiede

Hier werden die Unterschiede zwischen zwei Versionen angezeigt.

Link zu dieser Vergleichsansicht

adminstoriesstrace [20120903 05:54] (aktuell)
Dirk Deimeke angelegt
Zeile 1: Zeile 1:
 +====== strace ======
  
 +  * Urspruenglicher Autor: Ramon Kukla
 +  * Urspruengliches Datum: 16.09.2011
 +
 +Ist schon wieder Freitag? Ja tatsaechlich,​ ist es. Also los...
 +
 +Es gibt ja verschiedene Wege mit Problemen umzugehen. Hat man bei Problemen entsprechende Logs oder Rueckmeldungen,​ kann man damit beispielsweise die Suchmaschine seiner Wahl bemuehen. Oder die Meldung ist schon so eindeutig, dass man gleich weiss wo man dran ist.
 +
 +Es passiert aber auch immer wieder, dass ein Tool nicht tut was man erwartet, man aber auch keine Rueckmeldung bekommt. Fuer mich ist das oft der Punkt an dem ich aus einer von zwei Moeglichkeiten waehle. Ist das Tool neu und nicht wichtig genug, fliegt es wieder vom Rechner. Nutze ich das Tool aber schon laenger, oder ist es wichtig, bzw. gibt es keine sinnvolle Alternative,​ nehme ich gerne ''​strace''​ zur Hand.
 +
 +Die man-Page von strace sagt, dass man "​system calls und signals"​ verfolgen kann. Und das trifft es auch ganz gut soweit. So kann man beispielsweise einfach mal ein ''​strace whoami''​ absetzen und schauen was (gekuerzt) raus kommt. ​
 +
 +<​code>​execve("/​usr/​bin/​whoami",​ ["​whoami"​],​ [/* 47 vars */]) = 0
 +brk(0) ​                                 = 0x9707000
 +access("/​etc/​ld.so.nohwcap",​ F_OK)      = -1 ENOENT (No such file or directory)
 +mmap2(NULL, 8192, PROT_READ|PROT_WRITE,​ MAP_PRIVATE|MAP_ANONYMOUS,​ -1, 0) = 0xb781e000
 +access("/​etc/​ld.so.preload",​ R_OK)      = -1 ENOENT (No such file or directory)
 +open("/​etc/​ld.so.cache",​ O_RDONLY) ​     = 3
 +fstat64(3, {st_mode=S_IFREG|0644,​ st_size=64435,​ ...}) = 0
 +mmap2(NULL, 64435, PROT_READ, MAP_PRIVATE,​ 3, 0) = 0xb780e000
 +close(3) ​                               = 0
 +access("/​etc/​ld.so.nohwcap",​ F_OK)      = -1 ENOENT (No such file or directory)
 +open("/​lib/​i386-linux-gnu/​libc.so.6",​ O_RDONLY) = 3
 +read(3, "​\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\220o\1\0004\0\0\0"​...,​ 512) = 512
 +fstat64(3, {st_mode=S_IFREG|0755,​ st_size=1434180,​ ...}) = 0
 +mmap2(NULL, 1444360, PROT_READ|PROT_EXEC,​ MAP_PRIVATE|MAP_DENYWRITE,​ 3, 0) = 0x110000
 +mprotect(0x26a000,​ 4096, PROT_NONE) ​    = 0
 +mmap2(0x26b000,​ 12288, PROT_READ|PROT_WRITE,​ MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE,​ 3, 0x15a) = 0x26b000
 +mmap2(0x26e000,​ 10760, PROT_READ|PROT_WRITE,​ MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS,​ -1, 0) = 0x26e000
 +...
 +write(1, "​ramon\n",​ 6ramon
 +)                  = 6
 +close(1) ​                               = 0
 +munmap(0xb781c000,​ 4096)                = 0
 +close(2) ​                               = 0
 +exit_group(0) ​                          = ?</​code>​
 +
 +Die Ausgabe von strace ist auch schon im Standard relativ umfangreich. Wobei man sich nicht von der schieren Menge erschrecken lassen sollte. Man wird viele Eintraege sehen, die beinahe selbst erklaerend sind. Ein Teil "​open",​ "​close",​ "​read"​ oder "​exit"​. Natuerlich hat man auch Eintraege, die nicht auf den ersten Blick klar sind. Da hilft dann ein dezener Blick in "​[[http://​www.kernel.org/​doc/​man-pages/​online/​pages/​man2/​syscalls.2.html|syscalls - Linux system calls]]"​ auf kernel.org (was hoffentlich bald mal wieder erreichbar ist). 
 +
 +Ein haeufiger Fehler ist, dass eine Datei nicht gefunden oder geoeffnet (z.B. Berechtigung) werden kann. Wird eine Datei nicht gefunden kann das in einem strace etwa wie folgt ausschauen.
 +
 +<​code>​open("/​lib/​libgcrypt.so.11",​ O_RDONLY) = -1 ENOENT (No such file or directory)</​code>​
 +
 +Hier wird die Datei ''​libgcrypt.so.11''​ nicht gefunden. Fairerweise muss gesagt werden, dass es nicht immer reicht den Fehler zu kennen. Denn... Ich sehe zwar, dass die Datei nicht gefunden wird, muss mich aber zumindest noch schlau machen wie ich diese nun auf mein System bekomme. Ist aber ein anderes Thema.
 +
 +strace hat, wie so viele tolle Kommandos, umfangreiche Optionen. Eine sehr interessante Option, die einem schon mal zeigt was auf einen zukommt, ist ''​-c''​.
 +
 +<code bash>​ramon@bullfrog ~ $ strace -c whoami
 +ramon
 +% time     ​seconds ​ usecs/​call ​    ​calls ​   errors syscall
 +------ ----------- ----------- --------- --------- ----------------
 +  -nan    0.000000 ​          ​0 ​        ​9 ​          read
 +  -nan    0.000000 ​          ​0 ​        ​1 ​          write
 +  -nan    0.000000 ​          ​0 ​       38        13 open
 +  -nan    0.000000 ​          ​0 ​       29           close
 +  -nan    0.000000 ​          ​0 ​        ​1 ​          ​execve
 +  -nan    0.000000 ​          ​0 ​        ​7 ​        7 access
 +  -nan    0.000000 ​          ​0 ​        ​3 ​          brk
 +  -nan    0.000000 ​          ​0 ​        ​7 ​          ​munmap
 +  -nan    0.000000 ​          ​0 ​        ​8 ​          ​mprotect
 +  -nan    0.000000 ​          ​0 ​        ​2 ​          ​_llseek
 +  -nan    0.000000 ​          ​0 ​       34           mmap2
 +  -nan    0.000000 ​          ​0 ​       26           ​fstat64
 +  -nan    0.000000 ​          ​0 ​        ​1 ​          ​geteuid32
 +  -nan    0.000000 ​          ​0 ​        ​1 ​          ​fcntl64
 +  -nan    0.000000 ​          ​0 ​        ​1 ​          ​set_thread_area
 +  -nan    0.000000 ​          ​0 ​        ​2 ​          ​socket
 +  -nan    0.000000 ​          ​0 ​        ​2 ​        2 connect
 +------ ----------- ----------- --------- --------- ----------------
 +100.00 ​   0.000000 ​                  ​172 ​       22 total</​code>​
 +
 +Auch interessant,​ wenn es *noch* tiefer gehen soll, ist die Option ''​-f''​. Hierbei wird dann auch den Kinderprozessen gefolgt. Hier mal, gekuerzt, was ''​strace -c sh -c 'for i in $(cat dupes_*); do echo $i; done''​ ausgibt...
 +
 +<code bash>% time     ​seconds ​ usecs/​call ​    ​calls ​   errors syscall
 +------ ----------- ----------- --------- --------- ----------------
 + ​84.22 ​   0.004093 ​          ​0 ​    ​83870 ​          write
 + ​15.25 ​   0.000741 ​          ​0 ​    ​26798 ​          read
 +  0.53    0.000026 ​         26         ​1 ​          wait4
 +...
 +  0.00    0.000000 ​          ​0 ​        ​1 ​          ​set_thread_area
 +------ ----------- ----------- --------- --------- ----------------
 +100.00 ​   0.004860 ​               110717 ​        3 total</​code>​
 +
 +...und nachfolgend <​code>​strace -f -c sh -c 'for i in $(cat dupes_*); do echo $i; done</​code>​ (also mit Kinderprozessen).
 +
 +<code bash>% time     ​seconds ​ usecs/​call ​    ​calls ​   errors syscall
 +------ ----------- ----------- --------- --------- ----------------
 + ​85.34 ​   0.007601 ​          ​0 ​    ​83980 ​          write
 + ​14.35 ​   0.001278 ​          ​0 ​    ​26923 ​          read
 +  0.31    0.000028 ​         28         ​1 ​          wait4
 +...
 +  0.00    0.000000 ​          ​0 ​        ​2 ​          ​set_thread_area
 +------ ----------- ----------- --------- --------- ----------------
 +100.00 ​   0.008907 ​               111103 ​       24 total</​code>​
 +
 +Man sieht, mit strace kann man viel Spass haben. Aber neben dem Spass hilft es in der Tat durchaus Problemen auf den Grund zu gehen. Man kann strace uebrigens auch an laufende Prozesse anhaengen. Allerdings habe ich schon mal gesehen, dass beim Beenden von strace auch der Prozess abgeschmiert ist. Das ist, meine ich, nicht normal, sollte man aber im Hinterkopf behalten. Vor allem wenn man ein Prozess auf einem produktiven Server mit 500 Benutzern untersuchen will.
 +
 +[[adminstoriesartikel|Zurück zur Uebersicht]]