adminstoriesstrace

no way to compare when less than two revisions

Unterschiede

Hier werden die Unterschiede zwischen zwei Versionen angezeigt.


adminstoriesstrace [20120903 05:54] (aktuell) – angelegt Dirk Deimeke
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                             read
 +  -nan    0.000000                             write
 +  -nan    0.000000                  38        13 open
 +  -nan    0.000000                  29           close
 +  -nan    0.000000                             execve
 +  -nan    0.000000                           7 access
 +  -nan    0.000000                             brk
 +  -nan    0.000000                             munmap
 +  -nan    0.000000                             mprotect
 +  -nan    0.000000                             _llseek
 +  -nan    0.000000                  34           mmap2
 +  -nan    0.000000                  26           fstat64
 +  -nan    0.000000                             geteuid32
 +  -nan    0.000000                             fcntl64
 +  -nan    0.000000                             set_thread_area
 +  -nan    0.000000                             socket
 +  -nan    0.000000                           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               83870           write
 + 15.25    0.000741               26798           read
 +  0.53    0.000026          26                   wait4
 +...
 +  0.00    0.000000                             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               83980           write
 + 14.35    0.001278               26923           read
 +  0.31    0.000028          28                   wait4
 +...
 +  0.00    0.000000                             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]]
  • adminstoriesstrace.txt
  • Zuletzt geändert: 20120903 05:54
  • von Dirk Deimeke