original in en Guido Socher
en to de Katja Socher
Guido mag die M�glichkeiten, die ein Open Source System wie Linux beim l�sen von Problemen bietet. Man kann wirklich die Ursache des Problems finden, wenn man sich entsprechend viel Zeit daf�r nimmt.
In einem closed source System gibt es normalerweise nur zwei Optionen:
|
Trotz dieser Hindernisse gibt es einige Dinge, die man tun kann, ohne den ganzen Code zu lesen und ohne zu lernen, wie das Programm intern funktioniert.
#include <syslog.h> void openlog(const char *ident, int option, int facility); void syslog(int priority, const char *format, ...); void closelog(void); facility klassifiziert den Typ der Applikation, die die Message sendet. priority entscheidet �ber die Wichtigkeit der Message. M�gliche Werte in der Reihenfolge der Wichtigkeit sind: LOG_EMERG LOG_ALERT LOG_CRIT LOG_ERR LOG_WARNING LOG_NOTICE LOG_INFO LOG_DEBUGMit diesem C-interface kann jede Applikation, die in C geschrieben wurde, ins System-log schreiben. Andere Sprachen haben �hnliche APIs. Sogar Shellskripte k�nnen mit dem folgenden Befehl ins Log schreiben:
logger -p err "this text goes to /var/log/messages"Eine Standard syslog Konfiguration (file /etc/syslog.conf) sollte unter anderem eine Zeile haben, die wie folgt aussieht:
# Log anything (except mail) of level info or higher. # Don't log private authentication messages. *.info;mail.none;authpriv.none /var/log/messagesDas "*.info" logt alles mit einem Priorit�tlevel LOG_INFO oder h�her. Um mehr Informationen in /var/log/messages zu erhalten, kannst "*.debug" benutzen und syslog erneut starten (/etc/init.d/syslog restart).
1) La� tail -f /var/log/messages laufen und starte dann die Applikation, die fehlerhaft ist, von einer anderen Shell aus. Vielleicht bekommst du bereits einige Hinweise, was schief l�uft. 2) Wenn Schritt 1) nicht ausreicht, dann editiere /etc/syslog.conf und �ndere *.info zu *.debug. La� "/etc/init.d/syslog restart" laufen und wiederhole Schritt 1).Das Problem mit dieser Methode ist, da� sie vollst�ndig davon abh�ngt, was der Entwickler in seinem Code gemacht hat. Wenn er keine syslog Aufrufe an Schl�sselpunkten hinzugef�gt hat, dann siehst du eventuell �berhaupt nichts. In anderen Worten, man kann nur Probleme finden, bei denen der Entwickler schon vorhergesehen hat, da� etwas schief gehen k�nnte.
strace your_applicationHier ist ein Beispiel:
# strace /usr/sbin/uucico execve("/usr/sbin/uucico", ["/usr/sbin/uucico", "-S", "uucpssh", "-X", "11"], [/* 36 vars */]) = 0 uname({sys="Linux", node="brain", ...}) = 0 brk(0) = 0x8085e34 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40014000 open("/etc/ld.so.preload", O_RDONLY) = -1 ENOENT (No such file or directory) open("/etc/ld.so.cache", O_RDONLY) = 3 fstat64(3, {st_mode=S_IFREG|0644, st_size=70865, ...}) = 0 mmap2(NULL, 70865, PROT_READ, MAP_PRIVATE, 3, 0) = 0x40015000 close(3) = 0 open("/lib/libnsl.so.1", 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\300;\0"..., 1024) = 1024 fstat64(3, {st_mode=S_IFREG|0755, st_size=89509, ...}) = 0 mmap2(NULL, 84768, PROT_READ|PROT_EXEC, MAP_PRIVATE, 3, 0) = 0x40027000 mprotect(0x40039000, 11040, PROT_NONE) = 0 mmap2(0x40039000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 3, 0x11) = 0x40039000 mmap2(0x4003a000, 6944, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x4003a000 close(3) = 0 open("/lib/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`X\1\000"..., 1024) = 1024 fstat64(3, {st_mode=S_IFREG|0755, st_size=1465426, ...}) = 0 mmap2(NULL, 1230884, PROT_READ|PROT_EXEC, MAP_PRIVATE, 3, 0) = 0x4003c000 mprotect(0x40163000, 22564, PROT_NONE) = 0 mmap2(0x40163000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 3, 0x126) = 0x40163000 mmap2(0x40166000, 10276, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x40166000 close(3) = 0 munmap(0x40015000, 70865) = 0 brk(0) = 0x8085e34 brk(0x8086e34) = 0x8086e34 brk(0) = 0x8086e34 brk(0x8087000) = 0x8087000 open("/usr/conf/uucp/config", O_RDONLY) = -1 ENOENT (No such file or directory) rt_sigaction(SIGINT, NULL, {SIG_DFL}, 8) = 0 rt_sigaction(SIGINT, {0x806a700, [], SA_RESTORER|SA_INTERRUPT, 0x40064d58}, NULL, 8) = 0 rt_sigaction(SIGHUP, NULL, {SIG_DFL}, 8) = 0 rt_sigaction(SIGHUP, {0x806a700, [], SA_RESTORER|SA_INTERRUPT, 0x40064d58}, NULL, 8) = 0 rt_sigaction(SIGQUIT, NULL, {SIG_DFL}, 8) = 0 rt_sigaction(SIGQUIT, {0x806a700, [], SA_RESTORER|SA_INTERRUPT, 0x40064d58}, NULL, 8) = 0 rt_sigaction(SIGTERM, NULL, {SIG_DFL}, 8) = 0 rt_sigaction(SIGTERM, {0x806a700, [], SA_RESTORER|SA_INTERRUPT, 0x40064d58}, NULL, 8) = 0 rt_sigaction(SIGPIPE, NULL, {SIG_DFL}, 8) = 0 rt_sigaction(SIGPIPE, {0x806a700, [], SA_RESTORER|SA_INTERRUPT, 0x40064d58}, NULL, 8) = 0 getpid() = 1605 getrlimit(RLIMIT_NOFILE, {rlim_cur=1024, rlim_max=1024}) = 0 close(3) = -1 EBADF (Bad file descriptor) close(4) = -1 EBADF (Bad file descriptor) close(5) = -1 EBADF (Bad file descriptor) close(6) = -1 EBADF (Bad file descriptor) close(7) = -1 EBADF (Bad file descriptor) close(8) = -1 EBADF (Bad file descriptor) close(9) = -1 EBADF (Bad file descriptor) fcntl64(0, F_GETFD) = 0 fcntl64(1, F_GETFD) = 0 fcntl64(2, F_GETFD) = 0 uname({sys="Linux", node="brain", ...}) = 0 umask(0) = 022 socket(PF_UNIX, SOCK_STREAM, 0) = 3 connect(3, {sa_family=AF_UNIX, path="/var/run/.nscd_socket"}, 110) = -1 ENOENT (No such file or directory) close(3) = 0 open("/etc/nsswitch.conf", O_RDONLY) = 3 fstat64(3, {st_mode=S_IFREG|0644, st_size=499, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40015000 read(3, "# /etc/nsswitch.conf:\n# $Header:"..., 4096) = 499 read(3, "", 4096) = 0 close(3) = 0 munmap(0x40015000, 4096) = 0 open("/etc/ld.so.cache", O_RDONLY) = 3 fstat64(3, {st_mode=S_IFREG|0644, st_size=70865, ...}) = 0 mmap2(NULL, 70865, PROT_READ, MAP_PRIVATE, 3, 0) = 0x40015000 close(3) = 0 open("/lib/libnss_compat.so.2", 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\300\25"..., 1024) = 1024 fstat64(3, {st_mode=S_IFREG|0755, st_size=50250, ...}) = 0 mmap2(NULL, 46120, PROT_READ|PROT_EXEC, MAP_PRIVATE, 3, 0) = 0x40169000 mprotect(0x40174000, 1064, PROT_NONE) = 0 mmap2(0x40174000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 3, 0xa) = 0x40174000 close(3) = 0 munmap(0x40015000, 70865) = 0 uname({sys="Linux", node="brain", ...}) = 0 brk(0) = 0x8087000 brk(0x8088000) = 0x8088000 open("/etc/passwd", O_RDONLY) = 3 fcntl64(3, F_GETFD) = 0 fcntl64(3, F_SETFD, FD_CLOEXEC) = 0 fstat64(3, {st_mode=S_IFREG|0644, st_size=1864, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40015000 _llseek(3, 0, [0], SEEK_CUR) = 0 read(3, "root:x:0:0:root:/root:/bin/bash\n"..., 4096) = 1864 close(3) = 0 munmap(0x40015000, 4096) = 0 getuid32() = 10 geteuid32() = 10 chdir("/var/spool/uucp") = 0 open("/usr/conf/uucp/sys", O_RDONLY) = -1 ENOENT (No such file or directory) open("/var/log/uucp/Debug", O_WRONLY|O_APPEND|O_CREAT|O_NOCTTY, 0600) = 3 fcntl64(3, F_GETFD) = 0 fcntl64(3, F_SETFD, FD_CLOEXEC) = 0 fcntl64(3, F_GETFL) = 0x401 (flags O_WRONLY|O_APPEND) fstat64(3, {st_mode=S_IFREG|0600, st_size=296, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40015000 _llseek(3, 0, [0], SEEK_CUR) = 0 open("/var/log/uucp/Log", O_WRONLY|O_APPEND|O_CREAT|O_NOCTTY, 0644) = 4 fcntl64(4, F_GETFD) = 0 fcntl64(4, F_SETFD, FD_CLOEXEC) = 0 fcntl64(4, F_GETFL) = 0x401 (flags O_WRONLY|O_APPEND)Was sehen wir hier? La�t uns z.B. die folgenden Zeilen anschauen:
open("/etc/ld.so.preload", O_RDONLY) = -1 ENOENT (No such file or directory) open("/etc/ld.so.cache", O_RDONLY) = 3Das Programm versucht, /etc/ld.so.preload zu lesen und versagt, dann macht es weiter und liest /etc/ld.so.cache. Hier ist es erfolgreich und bekommt File-descriptor 3 zugewiesen. Nun mu� das Scheitern beim Lesen von /etc/ld.so.preload nicht das Problem sein, da das Programm vielleicht nur versucht, die Datei zu lesen und zu benutzen, wenn m�glich. In anderen Worten, es ist nicht unbedingt ein Problem, wenn ein Programm eine Datei nicht lesen kann. Es h�ngt alles vom Aufbau des Programms ab. La�t uns alle open Aufrufe in der Ausgabe von strace anschauen:
open("/usr/conf/uucp/config", O_RDONLY)= -1 ENOENT (No such file or directory) open("/etc/nsswitch.conf", O_RDONLY) = 3 open("/etc/ld.so.cache", O_RDONLY) = 3 open("/lib/libnss_compat.so.2", O_RDONLY) = 3 open("/etc/passwd", O_RDONLY) = 3 open("/usr/conf/uucp/sys", O_RDONLY) = -1 ENOENT (No such file or directory) open("/var/log/uucp/Debug", O_WRONLY|O_APPEND|O_CREAT|O_NOCTTY, 0600) = 3 open("/var/log/uucp/Log", O_WRONLY|O_APPEND|O_CREAT|O_NOCTTY, 0644) = 4 open("/etc/ld.so.preload", O_RDONLY) = -1 ENOENT (No such file or directory) open("/etc/ld.so.cache", O_RDONLY) = 3Das Programm versucht nun, /usr/conf/uucp/config zu lesen. Oh! Das ist komisch, ich habe das config file in /etc/uucp/config ! ... und es gibt keine Zeile, wo das Programm versucht, /etc/uucp/config zu �ffnen. Das ist der Fehler. Offentsichtlich wurde das Programm zur Kompilierzeit f�r den falschen Speicherplatz des Konfigurationsfiles konfiguriert.
# ulimit -c unlimited # ./lshref -i index.html,index.htm test.html Segmentation fault (core dumped) Exit 139Das core-file kann jetzt mit dem gdb debugger benutzt werden, um herauszufinden, was schiefgeht. Bevor du gdb startest, kannst du �berpr�fen, da� du wirklich das richtige core-file anschaust:
# file core.16897 core.16897: ELF 32-bit LSB core file Intel 80386, version 1 (SYSV), SVR4-style, from 'lshref'OK, lshref ist ein Programm, das abgest�rzt ist, la�t es uns deshalb in gdb laden. Um gdb zum Benutzen mit einem core-file aufzurufen, mu�t du nicht nur das core-file spezifizieren, sondern auch den Namen der ausf�hrbaren Datei, die zum core-file dazugeh�rt.
# gdb ./lshref core.23061 GNU gdb Linux (5.2.1-4) Copyright 2002 Free Software Foundation, Inc. GDB is free software, covered by the GNU General Public License, and you are welcome to change it and/or distribute copies of it under certain conditions. Type "show copying" to see the conditions. There is absolutely no warranty for GDB. Type "show warranty" for details. Core was generated by `./lshref -i index.html,index.htm test.html'. Program terminated with signal 11, Segmentation fault. Reading symbols from /lib/libc.so.6...done. Loaded symbols for /lib/libc.so.6 Reading symbols from /lib/ld-linux.so.2...done. Loaded symbols for /lib/ld-linux.so.2 #0 0x40095e9d in strcpy () from /lib/libc.so.6 (gdb)Jetzt wissen wir, da� das Programm abst�rzt, w�hrend es versucht, ein strcpy zu machen. Das Problem ist, da� es eventuell viele Stellen im Code gibt, wo strcpy benutzt wird.
gdb ./lshref core.23061 GNU gdb Linux (5.2.1-4) Copyright 2002 Free Software Foundation, Inc. GDB is free software, covered by the GNU General Public License, and you are welcome to change it and/or distribute copies of it under certain conditions. Type "show copying" to see the conditions. There is absolutely no warranty for GDB. Type "show warranty" for details. Core was generated by `./lshref -i index.html,index.htm test.html'. Program terminated with signal 11, Segmentation fault. Reading symbols from /lib/libc.so.6...done. Loaded symbols for /lib/libc.so.6 Reading symbols from /lib/ld-linux.so.2...done. Loaded symbols for /lib/ld-linux.so.2 #0 0x40095e9d in strcpy () from /lib/libc.so.6 (gdb) backtrace #0 0x40095e9d in strcpy () from /lib/libc.so.6 Cannot access memory at address 0xbfffeb38 (gdb) run ./lshref -i index.html,index.htm test.html Starting program: /home/guido/lshref ./lshref -i index.html,index.htm test.html Program received signal SIGSEGV, Segmentation fault. 0x40095e9d in strcpy () from /lib/libc.so.6 (gdb) backtrace #0 0x40095e9d in strcpy () from /lib/libc.so.6 #1 0x08048d09 in string_to_list () #2 0x080494c8 in main () #3 0x400374ed in __libc_start_main () from /lib/libc.so.6 (gdb)Jetzt k�nnen wir sehen, da� Funktion main() string_to_list() aufgerufen hat und von string_to_list wird strcpy() aufgerufen. Wir gehen zu string_to_list() und schauen uns den Code an:
char **string_to_list(char *string){ char *dat; char *chptr; char **array; int i=0; dat=(char *)malloc(strlen(string))+5000; array=(char **)malloc(sizeof(char *)*51); strcpy(dat,string);Diese malloc Zeile sieht wie ein Tippfehler aus. Wahrscheinlich sollte sie folgenderma�en lauten:
dat=(char *)malloc(strlen(string)+5000);
#includeWir kompilieren es:#include int add(int *p,int a,int b) { *p=a+b; return(*p); } int main(void) { int i; int *p = 0; /* a null pointer */ printf("result is %d\n", add(p,2,3)); return(0); }
gcc -Wall -g -o exmp exmp.cLassen es laufen...
# ./exmp Segmentation fault (core dumped) Exit 139
gdb exmp core.5302 GNU gdb Linux (5.2.1-4) Copyright 2002 Free Software Foundation, Inc. GDB is free software, covered by the GNU General Public License, and you are welcome to change it and/or distribute copies of it under certain conditions. Type "show copying" to see the conditions. There is absolutely no warranty for GDB. Type "show warranty" for details. Core was generated by `./exmp'. Program terminated with signal 11, Segmentation fault. Reading symbols from /lib/libc.so.6...done. Loaded symbols for /lib/libc.so.6 Reading symbols from /lib/ld-linux.so.2...done. Loaded symbols for /lib/ld-linux.so.2 #0 0x08048334 in add (p=Cannot access memory at address 0xbfffe020 ) at exmp.c:6 6 *p=a+b;gdb sagt uns nun, da� der Fehler in Zeile 6 gefunden wurde und da� Pointer "p" auf Memory zeigt, auf die nicht zugegriffen werden kann.