Kdump - Analyse - Gaëtan Trellu

Analyse d'un kernel   dump(crash, core)Analyse d'un kernel (crash, core) dump

IntroductionPré-requisAnalyse

Premiers pasÉtat de la mémoireLa backtrace, un indispensable de crashDésassembler une fonctionSourcesQui à fait quoi ?

ConclusionSources

IntroductionAprès le crash d'un serveur, l'administrateur système que vous êtes espère de tout son être qu'un crashdump soit disponible dans le répertoire /var/crash/ (si tel est la destination choisie). Dans cet exemple, la cause du crash du serveur sera liée au chargement d'un module noyau. Cedernier appellera dès son chargement la fonction du noyau Linux : panic()

Pré-requisLa lecture d'un   Linux se fait à l'aide de l'outil crash, ce dernier permet d'interpréter de manière lisible pour l'homme les donnéescrashdumpcontenues dans le fichier binaire.

# aptitude install crash gdb binutils

Le paquet   est nécessaire car il contient entre autre la commande   qui est utilisée par  . Sans cette commande l'erreurbinutils strings crashsuivante s'affichera au lancement de la commande   :crash

sh: 1: /usr/bin/strings: not found

Analyse

Dans le répertoire /var/crash/ doit se trouver un répertoire nommé de la date du crash sous la forme suivante (YYYYMMDDHHMM). Cerépertoire contient deux choses   :(sous Debian GNU/Linux)

lrwxrwxrwx 1 root root 55 Jul 22 19:36 kernel_link ->/usr/lib/debug/lib/modules/2.6.32-amd64/vmlinux-r-------- 1 root root 2050769968 Jul 22 19:47 vmcore.201307221946

Configuration de KdumpSi   n'est pas encore configuré sur le serveur alors je vous invite à parcourir la procédure suivante : Kdump Debian - Kdump

À lireCette analyse est effectuée depuis une distribution . Le analysé provient d'un serveur exécutant uneDebian GNU/Linux crashdumpdistribution Debian GNUX/Linux.Les différences avec les autres distributions sont minimes.

kernel_link est lien symbolique, il est créé à partir de la valeur   définie dans le fichier de configuration DEBUG_KERNEL /etc/default/kdum.p-tools

Premiers pas

En fonction de la taille du il est possible que crash soit un peu long rendre la main, c'est normal.crashdump

# crash kernel_link vmcore.201307221946

Résultat :

crash 6.0.6Copyright (C) 2002-2012 Red Hat, Inc.Copyright (C) 2004, 2005, 2006 IBM CorporationCopyright (C) 1999-2006 Hewlett-Packard CoCopyright (C) 2005, 2006 Fujitsu LimitedCopyright (C) 2006, 2007 VA Linux Systems Japan K.K.Copyright (C) 2005 NEC CorporationCopyright (C) 1999, 2002, 2007 Silicon Graphics, Inc.Copyright (C) 1999, 2000, 2001, 2002 Mission Critical Linux, Inc.This program is free software, covered by the GNU General Public License,and you are welcome to change it and/or distribute copies of it undercertain conditions. Enter "help copying" to see the conditions.This program has absolutely no warranty. Enter "help warranty" fordetails. GNU gdb (GDB) 7.3.1Copyright (C) 2011 Free Software Foundation, Inc.License GPLv3+: GNU GPL version 3 or later<http://gnu.org/licenses/gpl.html>This is free software: you are free to change and redistribute it.There is NO WARRANTY, to the extent permitted by law. Type "show copying"and "show warranty" for details.This GDB was configured as "x86_64-unknown-linux-gnu"... KERNEL: kernel_link DUMPFILE: vmcore.201307221946 CPUS: 1 DATE: Mon Jul 22 19:45:42 2013 UPTIME: 00:09:40LOAD AVERAGE: 0.01, 0.02, 0.00 TASKS: 64 NODENAME: kernel-debug RELEASE: 2.6.32-amd64 VERSION: #1 SMP Mon Jul 8 15:25:50 EDT 2013 MACHINE: x86_64 (1995 Mhz) MEMORY: 2 GB PANIC: "[ 580.890926] Kernel panic - not syncing: Panic functioncalled, don't be worried the system will be down !" PID: 2655 COMMAND: "insmod" TASK: ffff88007b0b8cc0 [THREAD_INFO: ffff88007a0c8000] CPU: 0 STATE: TASK_RUNNING (PANIC)

Par défaut décide d'afficher les du ainsi que des copyrights, pour passer outre toutes ces informations ilcrash "méta-données" crashdumpexiste le paramètre à positionner juste avant   . -s kernel_link

Les premières informations fournies sont les suivantes :

Le nombre de CPULa mémoire vive totaleLa date exacte du crashLa charge du serveur au moment du crash

Le nombre de processus au moment du crashLa version du noyau utiliséetc...

La première interprétation des informations serait la suivante :( style ) Cluedo

HomicideLe décès eu lieu le à , la charge présente sur était moindre. Seuls étaient en22 juillet 2013 19h45 Mr kernel_debug 64 processuscours d'exécution au moment du drame.Le sujet est un serveur de type cadencé à , doté de de mémoire, ses origines remontent à l'an 1 processeur 64Bits 2Ghz 2Go 2.6.

.32

Le coupable, un jeune processus nommé connu de nos services sous le . Il causa le décès du sujet par insmod PID 2655 Kernel et le coup mortel fut exécuté dans le .panic CPU 0

Le mobile du crime : "Panic function called, don't be worried the system will be down !"

Les informations indiquées permettent déjà d'avoir une idée de ce qui s'est passé sur le serveur, un . kernel panic

État de la mémoire

Il est intéressant de connaître l'état de la mémoire au moment du crash, savoir par exemple si l' est passé faire le ménage...OOM killer

crash> kmem -i

Résultat :

PAGES TOTAL PERCENTAGE TOTAL MEM 474877 1.8 GB ---- FREE 437169 1.7 GB 92% of TOTAL MEM USED 37708 147.3 MB 7% of TOTAL MEM SHARED 6007 23.5 MB 1% of TOTAL MEM BUFFERS 4375 17.1 MB 0% of TOTAL MEM CACHED 17116 66.9 MB 3% of TOTAL MEM SLAB 9631 37.6 MB 2% of TOTAL MEMTOTAL SWAP 0 0 ---- SWAP USED 0 0 100% of TOTAL SWAP SWAP FREE 0 0 0% of TOTAL SWAP

Dans le cas présent la consommation mémoire du serveur au moment du crash n'est pas la raison du , il reste de lakernel panic 92%mémoire disponible. Il est donc peut probable que la piste d'un soit à suivre.Out Of Memory

La backtrace, un indispensable de crash

La commande   de l'outil  est un must dans l'analyse de . Indispensable mais pas obligatoirebt (backtrace) crash crashdump (non ce n'est pas

, il est possible de passer par les commandes et pour obtenir à peu de chose près les mêmes informations.une contradiction ) log runq

bt permet d'obtenir de plus amples informations sur le processus responsable du crash du serveur.

crash> bt

Résultat :

PID: 2655 TASK: ffff88007b0b8cc0 CPU: 0 COMMAND: "insmod" #0 [ffff88007a0c9d60] machine_kexec at ffffffff810363e4 #1 [ffff88007a0c9dd0] crash_kexec at ffffffff810e68e2 #2 [ffff88007a0c9ea0] panic at ffffffff8154d0f3 #3 [ffff88007a0c9f10] init_module at ffffffffa018b025 [panic] #4 [ffff88007a0c9f20] do_one_initcall at ffffffff8100204c #5 [ffff88007a0c9f50] sys_init_module at ffffffff810db4c6 #6 [ffff88007a0c9f80] system_call_fastpath at ffffffff8100b182 RIP: 00007f31d21fa14a RSP: 00007fffb9a1b1e8 RFLAGS: 00010206 RAX: 00000000000000af RBX: ffffffff8100b182 RCX: 00007f31d21f648a RDX: 00007f31d24b9f88 RSI: 000000000004b6ce RDI: 00007f31d288a000 RBP: 00007f31d2fbc2a0 R8: 0000000000000004 R9: 0000000000000000 R10: 00007f31d21f648a R11: 0000000000000206 R12: 0000000000000000 R13: 00007f31d2fbb090 R14: 00007f31d24b9f88 R15: 00007f31d2fbc1a0 ORIG_RAX: 00000000000000af CS: 0033 SS: 002b

On récupère certaines informations déjà obtenues plus haut, comme par exemple :

Le PID (2655)L'ID du CPU qui exécutait le processus (0)La commande exécutée (insmod)

Mais le plus intéressant est que la fonction causant l'exception ainsi que le sont indiqués !RIP

#6 [ffff88007a0c9f80] system_call_fastpath at ffffffff8100b182RIP: 00007f31d21fa14a

Au final ce que la backtrace nous apprend c'est que la fonction a été appelée par la fonction qui futmachine_kexec() crash_kernel()appelée par la fonction  elle même appelée par la fonction appelée par la fonction qui à son panic() init_module() do_one_initcall()tour fut appelée par finalement appelée par qui est la fonction qui a causé le crash dusys_init_module() system_call_fastpath()serveur. Toujours avec nous ?

La valeur   située à côté de la fonction   est un offset, cet offset indique l'endroit dans la fonctionffffffff8100b182 system_call_fastpath()qui a posé problème.

Désassembler une fonction

Connaître la fonction qui a causé le problème c'est utile certes mais qu'a t-elle fait pour causer un appel de la fonction ? La commande panic() permet de désassembler une fonction, en l'occurrence la fonction dis ainsi que son offset.system_call_fastpath()

RIP est un registre du processeur. Il contient l'adresse mémoire de l'instruction du programme en cours d'exécution. Exemple :

Le programme appelle plusieurs fonctions :panicdump.c (c'est un exemple farfelu)

open()read()close()

Si le programme est la cause du crash alors l'une des fonctions citées ci-dessus sera certainement dans le registre panicdump.c RIP

RIP / EIPEn fonction de l'architecture CPU les registres peuvent se nommer différemment et leur nombre peut varier.

x86 = Les registres se nomment et non , exemple : et non E(XX) R(XX) EIP RIPx86_64 = Tous les registres se nomment , il y en a de plus qu'en 32Bits R(XX) 8

Lien à consulter pour de plus amples informations : http://docs.oracle.com/cd/E19205-01/820-4220/

La fonction system_call_fastpath() peut aussi être appelée symbole.

Il est possible de traduire l'adresse virtuelle  parffffffff8100b182  system_call_fastpath+22, pour faire cela la commande sym sera

utilisée.

crash> sym ffffffff8100b182

Résultat :

ffffffff8100b182 (t) system_call_fastpath+22/usr/src/linux-2.6.32/arch/x86/kernel/entry_64.S: 505

L'option de dis permet de reverser une fonction, l'option permet d'obtenir plus de lisibilité. Exemple :-r -l

crash> dis -lr ffffffff8100b182

Ou :

crash> dis -lr system_call_fastpath+22

Résultat :

/usr/src/linux-2.6.32/arch/x86/kernel/entry_64.S: 5010xffffffff8100b16c <system_call_fastpath>: cmp $0x1fe,%rax/usr/src/linux-2.6.32/arch/x86/kernel/entry_64.S: 5020xffffffff8100b172 <system_call_fastpath+6>: ja 0xffffffff8100b262/usr/src/linux-2.6.32/arch/x86/kernel/entry_64.S: 5030xffffffff8100b178 <system_call_fastpath+12>: mov %r10,%rcx/usr/src/linux-2.6.32/arch/x86/kernel/entry_64.S: 5040xffffffff8100b17b <system_call_fastpath+15>: callq *-0x7ea96ba0(,%rax,8)/usr/src/linux-2.6.32/arch/x86/kernel/entry_64.S: 5050xffffffff8100b182 <system_call_fastpath+22>: mov %rax,0x20(%rsp)

Le désassemblage nous indique que la fonction  a essayé de copier le contenu du registre dans le registre system_call_fastpath()+22 RSP

, c'est cette instruction qui a causé une exception.RAX

Sources

 Le code source de cette fonction se trouve dans le fichier /usr/src/linux-2.6.32/arch/x86/kernel/entry_64.S

arch/x86/kernel/entry_64.S

system_call_fastpath: cmpq $__NR_syscall_max,%rax ja badsys movq %r10,%rcx call *sys_call_table(,%rax,8) # XXX: rip relative movq %rax,RAX-ARGOFFSET(%rsp)

1. 2.

Cette fonction regroupe des instructions d'assembleur pour des processeurs de type x86_64.

Qui à fait quoi ?

Il peut être parfois intéressant de savoir comment le processus a été exécuté, la commande ps propose deux options qui permettent de connaîtrel'arborescence père et l’arborescence fils . (si cette dernière existe)

-p : affiche l'arborescence père-c : affiche l'arborescence fils

Dans le cas suivant, le processus sera passé au peigne fin.2655

crash> ps -p 2655

Résultat :

PID: 0 TASK: ffffffff81875020 CPU: 0 COMMAND: "swapper" PID: 1 TASK: ffff88007eff4040 CPU: 0 COMMAND: "init" PID: 1968 TASK: ffff88007a87d1c0 CPU: 0 COMMAND: "sshd" PID: 1998 TASK: ffff88007d66c140 CPU: 0 COMMAND: "sshd" PID: 2000 TASK: ffff88007ab7c640 CPU: 0 COMMAND: "bash" PID: 2655 TASK: ffff88007b0b8cc0 CPU: 0 COMMAND: "insmod"

La commande a été exécutée depuis un terminal  par un utilisateur connecté en .insmod bash SSH

En tant qu'administrateur système vous savez certainement que la commande permet de charger un module noyau or actuellement nousinsmodn'avons aucune information sur le module qui a été chargé par cette commande. Encore une fois la commande permet d'avoir de plus amplespsinformations sur l'environnement qui a exécuté la commande.

crash> ps -a 2655

Résultat :

La lettre présente dans les instructions et sont typiques des processeurs x86_64.q cmpq movq

Le processus est en fait l’ordonnanceur , il est présent autant de fois qu'il y a de cores sur le serveur.swapper (scheduler)

PID: 2655 TASK: ffff88007b0b8cc0 CPU: 0 COMMAND: "insmod"ARG: insmod panic.ko ENV: TERM=xterm SHELL=/bin/bash SSH_CLIENT=88.143.117.83 48720 22 SSH_TTY=/dev/pts/0 USER=root SSH_AUTH_SOCK=/tmp/ssh-Dk4T8LiOcC/agent.1998 MAIL=/var/mail/root PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin PWD=/root/panic_module LANG=en_US.UTF-8 SHLVL=1 HOME=/root LS_OPTIONS=--color=auto LOGNAME=root SSH_CONNECTION=88.143.117.83 48720 10.13.45.7 22 _=/sbin/insmod OLDPWD=/root

Les informations ci-dessous permettent de savoir que le module est le module qui a causé le   du serveur. Lepanic.ko kernel paniccoupable est physique car il s'est connecté à un terminal depuis SSH :

SSH_CLIENT=88.143.117.83SSH_TTY=/dev/pts/0USER=rootPWD=/root/panic_moduleARG: insmod panic.ko

En théorie le module devrait être chargé, pour le vérifier la commande sera utilisée.panic mod

crash> mod

Résultat :

MODULE NAME SIZE OBJECT FILEffffffffa0005500 ata_piix 24437 (not loaded) [CONFIG_KALLSYMS]ffffffffa000ba40 virtio 5094 (not loaded) [CONFIG_KALLSYMS]ffffffffa00113c0 virtio_ring 8858 (not loaded) [CONFIG_KALLSYMS]ffffffffa0017940 pata_acpi 3717 (not loaded) [CONFIG_KALLSYMS]ffffffffa001c4a0 virtio_pci 7141 (not loaded) [CONFIG_KALLSYMS]ffffffffa0020a60 ata_generic 3885 (not loaded) [CONFIG_KALLSYMS]ffffffffa0027780 virtio_net 17578 (not loaded) [CONFIG_KALLSYMS]ffffffffa002e620 virtio_blk 7501 (not loaded) [CONFIG_KALLSYMS]ffffffffa0045fc0 jbd 83562 (not loaded) [CONFIG_KALLSYMS]ffffffffa0057240 mbcache 7945 (not loaded) [CONFIG_KALLSYMS]ffffffffa008b280 ext3 244318 (not loaded) [CONFIG_KALLSYMS]ffffffffa00af300 i2c_core 31840 (not loaded) [CONFIG_KALLSYMS]ffffffffa00bab60 i2c_piix4 13136 (not loaded) [CONFIG_KALLSYMS]ffffffffa00c0240 soundcore 8201 (not loaded) [CONFIG_KALLSYMS]ffffffffa00d2000 snd 76223 (not loaded) [CONFIG_KALLSYMS]ffffffffa00e3c60 virtio_balloon 4778 (not loaded) [CONFIG_KALLSYMS]ffffffffa00ec420 snd_timer 22985 (not loaded) [CONFIG_KALLSYMS]ffffffffa00f4760 snd_page_alloc 8710 (not loaded) [CONFIG_KALLSYMS]ffffffffa010b180 snd_pcm 93468 (not loaded) [CONFIG_KALLSYMS]ffffffffa011c640 snd_pcsp 8842 (not loaded) [CONFIG_KALLSYMS]ffffffffa0168140 ipv6 340294 (not loaded) [CONFIG_KALLSYMS]ffffffffa018b100 panic 1004 (not loaded) [CONFIG_KALLSYMS]

ConclusionDans la plupart des cas si le est lisible alors la source du crash du serveur pourra être identifiée.crashdump

La commande crash permet de faire énormément de choses avec un crashdump, dans cette procédure je n'ai utilisé que quelques commandes

mais sachez que la commande crash regorge de commandes.

pslogbt -frunqforeach bt -ftask

Bref, la commande listera toutes les commandes disponibles.help

Sources

Le module panic.ko utilisé pour cette procédurehttp://www.dedoimedo.com/computers/crash.htmlhttp://magazine.redhat.com/2007/08/15/a-quick-overview-of-linux-kernel-crash-dump-analysis/http://people.redhat.com/anderson/crash_whitepaper/

Debugger un n'est pas une chose facile, plusieurs paramètres peuvent entrer en cause. Si par exemple les sources d'uncrashdumpprogramme ne sont pas disponibles alors la difficulté sera accentuée.