Ou les quelques commandes gdb que j'utilise tout le temps car elles suffisent dans 95% des cas: run, backtrace, frame, print, list, break, watch, continue. Ce qui suit est un scénario réel.
La synthèse vocale d'Android, pico, est de très bonne qualité, mais quand on la compile et la lance sur une machine 64bits, proutch, elle segfaulte en beauté:
€ pico2wave -w test.wav foo zsh: segmentation fault pico2wave -w test.wav foo
Que faire ? Gdb ! Souvent la réponse que donne gdb est très éclairante !
Déjà, il faut recompiler le programme avec l'option -g, et puis éviter les optimisations qui rendent le débuggage souvent pénible, typiquement:
€ CFLAGS="-g -Og" ./configure && make
Attention par contre, parfois utiliser -Og risque de faire disparaître le bug ! Dans ce cas on est bien obligé de garder les options d'optimisations, mais gdb risque parfois de ne pas pouvoir afficher certaines valeurs.
€ ./pico2wave -w test.wav foo zsh: segmentation fault pico2wave -w test.wav foo
Ouf, cela segfaulte toujours. C'est une très bonne chose: c'est systématiquement reproductible !
Une astuce bien pratique est d'utiliser l'option --args de gdb, qui permet de rajouter simplement gdb --args devant la commande qu'on vient d'essayer.
€ gdb --args ./pico2wave -w test.wav foo GNU gdb (GDB) blabla blablabla ... (gdb)
gdb est prêt, on tape simplement r (raccourci pour run)
(gdb) r Starting program: /tmp/svox-1.0+git20100205/pico/.libs/lt-pico2wave -w test.wav foo Program received signal SIGSEGV, Segmentation fault. 0x00007ffff7711579 in picoos_deallocate (this=0x7ffff7285470, adr=0x7ffff736d100) at lib/picoos.c:579 579 if (cr->size > 0) { (gdb)
En voilà une ligne intéressante ! Le segfault ne peut venir que du déréférencement de cr a priori, utilisons p (raccourci pour print) pour voir le contenu de cr:
(gdb) p cr $1 = (MemCellHdr) 0x8000f736f9d8
Pointeur à la tronche un peu bizarre en effet (d'après /proc/$(pidof pico2wave)/maps), gdb confirme:
(gdb) p *cr Cannot access memory at address 0x8000f736f9d8
Regardons un peu d'où cela sort à l'aide de bt (raccourci pour backtrace):
(gdb) bt #0 0x00007ffff7711579 in picoos_deallocate (this=0x7ffff7285470, adr=0x7ffff736d100) at lib/picoos.c:579 #1 0x00007ffff7730462 in sigDeallocate (mm=0x7ffff7285470, sig_inObj=0x7ffff736d090) at lib/picosig2.c:367 #2 0x00007ffff772da10 in sigSubObjDeallocate (this=0x7ffff736ad78, mm=0x7ffff7285470) at lib/picosig.c:238 #3 0x00007ffff76f911f in picodata_disposeProcessingUnit (mm=0x7ffff7285470, this=0x7ffff7286c20) at lib/picodata.c:638 #4 0x00007ffff76f753c in ctrlSubObjDeallocate (this=0x7ffff7286b80, mm=0x7ffff7285470) at lib/picoctrl.c:274 #5 0x00007ffff76f911f in picodata_disposeProcessingUnit (mm=0x7ffff7285470, this=0x7ffff7285448) at lib/picodata.c:638 #6 0x00007ffff76f7c2e in picoctrl_disposeControl (mm=0x7ffff7285470, this=0x7ffff7285448) at lib/picoctrl.c:487 #7 0x00007ffff76f80b5 in picoctrl_disposeEngine (mm=0x7ffff7120030, rm=0x7ffff7120538, this=0x602c60) at lib/picoctrl.c:671 #8 0x00007ffff76effce in pico_disposeEngine (system=0x7ffff7120010, inoutEngine=0x602c60) at lib/picoapi.c:569 #9 0x0000000000401edc in main (argc=4, argv=0x7fffffffdc68) at bin/pico2wave.c:319 (gdb)
Hum, c'est pour le moins cryptique. Dans de nombreux cas cr aurait pu être un simple paramètre de notre fonction en cours, et il aurait fallu remonter à l'aide de la commande up à son appelant, et continuer à utiliser des p pour voir d'où cela vient, ce n'est apparemment pas le cas ici, cr n'est pas un paramètre. Regardons autour de notre ligne fâcheuse au sein de la fonction picoos_deallocate (l raccourci pour list):
(gdb) l 574 this->usedSize -= c->size; 575 576 cr = (MemCellHdr)((picoos_objsize_t)c + c->size); 577 cl = c->leftCell; 578 if (cl->size > 0) { 579 if (cr->size > 0) { 580 crr = (MemCellHdr)((picoos_objsize_t)cr + cr->size); 581 crr->leftCell = cl; 582 cl->size = ((cl->size + c->size) + cr->size); 583 cr->nextFree->prevFree = cr->prevFree;
Hum, ce code enfreint les règles usuelles de programmation, il y a du cast à tout va ! cr vient donc de c + c->size, regardons ceux-ci:
(gdb) p c $2 = (MemCellHdr) 0x7ffff736f9d8 (gdb) p c->size $3 = 4294967296
Re-ouille, la valeur de c a l'air raisonnable (on arrive même à la déréférencer), mais la valeur de c->size a l'air complètement incorrecte, c'est d'ailleurs exactement 0x100000000...
D'où vient cette valeur fantaisiste ? Soit un calcul est faux, soit on a un débordement depuis ailleurs.
Par chance, il y a peu de lignes de code qui donnent une valeur à size, on peut donc rapidement ajouter des printfs à côté de chacune d'entre elles. On n'obtient cependant que des valeurs raisonnables, et jamais 0x100000000, le problème est donc ailleurs... Comment faire ?
valgrind est un spécialiste des débordements de tampons, et d'habitude très efficace pour détecter les erreurs de pointeurs et d'allocation mémoire. Il est cependant inopérant ici: outre des tas de "Conditional jump or move depends on uninitialised value(s)", il termine lui aussi sur cette ligne cr->size sans avoir donné d'indice avant (c'est en fait parce que pico utilise son propre allocateur fait-maison, que valgrind ne peut donc pas débugguer...). Electric-Fence, un outil plus léger de détection de débordement de tampon, est inefficace ici pour la même raison.
Il reste la solution watch: en effet, si l'on exécute plusieurs fois le programme avec la distribution aléatoire des adresses désactivée (echo 0 > /proc/sys/kernel/randomize_va_space), on constate que l'adresse de c->size est toujours la même:
(gdb) p &c->size $1 = (long int *) 0x7ffff736f9d8
Il suffit donc de demander à gdb de s'arrêter quand cette valeur mémoire change. D'abord relancer depuis le début en s'arrêtant au début de la fonction main, avant que les choses tournent mal (b est le raccourci pour breakpoint):
(gdb) b main Breakpoint 1 at 0x4012ef: file bin/pico2wave.c, line 73. (gdb) r The program being debugged has been started already. Start it from the beginning? (y or n) y Starting program: /tmp/svox-1.0+git20100205/pico/.libs/lt-pico2wave -w test.wav foo Breakpoint 1, main (argc=4, argv=0x7fffffffdc58) at bin/pico2wave.c:73 73 char * wavefile = NULL;
On appelle watch pour indiquer à gdb quelle valeur mémoire surveiller:
(gdb) watch *(long int *) 0x7ffff736f9d8 Hardware watchpoint 2: *(long int *) 0x7ffff736f9d8
Notez bien Hardware ici: on ne fait surveiller qu'un entier en mémoire, gdb a donc pu demander au processeur de faire la surveillance lui-même, ce qui ne coûte rien en performance !
Note: watch permet évidemment aussi d'observer simplement une variable existante (watch mavariable), mais ici on ne sait pas vraiment quand elle commence à exister...
On peut maintenant continuer l'exécution (oui, les valeurs de taille négatives sont "normales"...):
(gdb) c Continuing. Hardware watchpoint 2: *(long int *) 0x7ffff736f9d8 Old value = 0 New value = 40120 picoos_allocate (this=0x7ffff7285470, byteSize=1024) at lib/picoos.c:539 539 c->size = cellSize; Current language: auto The current source language is "auto; currently c". (gdb) c Continuing. Hardware watchpoint 2: *(long int *) 0x7ffff736f9d8 Old value = 40120 New value = 1040 picoos_allocate (this=0x7ffff7285470, byteSize=1024) at lib/picoos.c:540 540 c2->leftCell = c; (gdb) c Continuing. Hardware watchpoint 4: *(long int *) 0x7ffff736f9d8 Old value = 1040 New value = -1040 picoos_allocate (this=0x7ffff7285470, byteSize=1024) at lib/picoos.c:556 556 adr = (void *)((picoos_objsize_t)c + this->usedCellHdrSize); (gdb) c Continuing. Hardware watchpoint 4: *(long int *) 0x7ffff736f9d8 Old value = -1040 New value = -4294967296 memset () at ../sysdeps/x86_64/memset.S:954 954 ../sysdeps/x86_64/memset.S: Aucun fichier ou dossier de ce type. in ../sysdeps/x86_64/memset.S Current language: auto The current source language is "auto; currently asm".
Ah, voilà quelque chose d'intéressant ! Regardons qui fait un memset et ainsi écrase notre champ size:
(gdb) bt #0 memset () at ../sysdeps/x86_64/memset.S:954 #1 0x00007ffff77151fa in picopal_mem_set (dest=0x7ffff736f63c, byte_val=0 '\000', length=928) at lib/picopal.c:258 #2 0x00007ffff7710bfb in picoos_mem_set (dest=0x7ffff736f63c, byte_val=0 '\000', length=928) at lib/picoos.c:184 #3 0x00007ffff7730cca in mel_2_lin_lookup (sig_inObj=0x7ffff736d090, scmeanMGC=10) at lib/picosig2.c:572 #4 0x00007ffff772e3d6 in sigProcess (this=0x7ffff736ad78, inReadPos=0, numinb=64, outWritePos=0, numoutb=0x7fffffffd758) at lib/picosig.c:540 #5 0x00007ffff772f2d1 in sigStep (this=0x7ffff736ad78, mode=0, numBytesOutput=0x7fffffffd7da) at lib/picosig.c:1104 #6 0x00007ffff76f72ab in ctrlStep (this=0x7ffff736f63c, mode=0, bytesOutput=0x7fffffffd826) at lib/picoctrl.c:153 #7 0x00007ffff76f821e in picoctrl_engFetchOutputItemBytes (this=0x7ffff7285428, buffer=0x7fffffffd9a0 "8\365\330\003", bufferSize=128, bytesReceived=0x7fffffffd99c) at lib/picoctrl.c:762 #8 0x00007ffff76f012c in pico_getData (engine=0x7ffff7285428, buffer=0x7fffffffd9a0, bufferSize=128, bytesReceived=0x7fffffffd99c, outDataType=0x7fffffffd99a) at lib/picoapi.c:650 #9 0x0000000000401d10 in main (argc=4, argv=0x7fffffffdc58) at bin/pico2wave.c:278 (gdb) p/x 0x7ffff736f63c + 928 $5 = 0x7ffff736f9dc
En faisant faire un petit calcul à gdb, on s'aperçoit qu'il s'en est fallu de très peu pour que notre champ size se fasse écraser par ce memset: juste 4 octets... Ce memset est encapsulé dans des fonctions pour faire joli, il faudrait donc utiliser up plusieurs fois pour remonter à l'appelant qui est dans la fonction mel_2_lin_lookup (3e dans la pile des appels). On peut aller plus rapidement avec frame:
(gdb) frame 3 #3 0x00007ffff7730cca in mel_2_lin_lookup (sig_inObj=0x7ffff736d090, scmeanMGC=10) at lib/picosig2.c:572 572 picoos_mem_set(XXr + m1, 0, i); Current language: auto The current source language is "auto; currently c". (gdb) l 567 XXr[0] = (picoos_int32) ((picoos_single) c1[0] * K1); 568 for (nI = 1; nI < m1; nI++) { 569 XXr[nI] = c1[nI] << shift; 570 } 571 i = sizeof(picoos_int32) * (PICODSP_FFTSIZE + 1 - m1); 572 picoos_mem_set(XXr + m1, 0, i); 573 dfct_nmf(m4, XXr); /* DFCT directly in fixed point */ 574 575 /* ***************************************************************************************** 576 Linear frequency scale envelope through interpolation.
C'est donc là le fautif, qui déborde chez nous. On a vu plus haut qu'il débordait de 4 octets. Si l'on regarde en détail, le memset efface le tampon XXr depuis l'octet 4*m1 jusqu'à l'octet 4*(PICODSP_FFTSIZE + 1). Est-ce que le +1 n'est pas superflu ?! Si l'on va voir le code qui alloue ce pointeur (en suivant les code source avec les tags, on trouve des définitions successives qui nous amènent à un champ wcep_pI, qui est en fait appelé int_vec28):
d32 = (picoos_int32 *) picoos_allocate(mm, sizeof(picoos_int32) * PICODSP_FFTSIZE); if (NULL == d32) { sigDeallocate(mm, sig_inObj); return PICO_ERR_OTHER; } sig_inObj->int_vec28 = d32;
Le +1 est effectivement a priori de trop ! Ou alors c'est l'allocation qui n'est pas assez grande ?! Là il faut discuter avec l'auteur, mais en tous cas on a trouvé un fautif clair ! Merci gdb !
Il n'y a en fait pas besoin de connaître beaucoup de commandes dans gdb. La première étape: r, bt, l et p, est en fait suffisante dans la plupart des cas ! Pour la plupart des autres cas, quelques b et watch peuvent aider beaucoup à trouver des bugs. On peut aussi essayer de les combiner avec reverse-continue.
Lorsque l'on débuggue un programme multithreadé, il est utile de pouvoir passer d'un thread à un autre:
(gdb) r Starting program: /tmp/test [Thread debugging using libthread_db enabled] [New Thread 0x7ffff7861710 (LWP 10981)] [New Thread 0x7ffff7060710 (LWP 10982)] ^C Program received signal SIGINT, Interrupt. 0x00007ffff7bcabe5 in pthread_join (threadid=140737346148112, thread_return=0x0) at pthread_join.c:89 89 pthread_join.c: Aucun fichier ou dossier de ce type. in pthread_join.c (gdb) bt #0 0x00007ffff7bcabe5 in pthread_join (threadid=140737346148112, thread_return=0x0) at pthread_join.c:89 #1 0x00000000004005fd in main () (gdb)
On est ici dans le thread main, qui est simplement en train d'attendre les threads qu'il a créés. On va voir la liste des threads:
(gdb) info thread 3 Thread 0x7ffff7060710 (LWP 10982) 0x00000000004005ac in f () 2 Thread 0x7ffff7861710 (LWP 10981) 0x00000000004005ac in f () * 1 Thread 0x7ffff7fce700 (LWP 10968) 0x00007ffff7bcabe5 in pthread_join ( threadid=140737346148112, thread_return=0x0) at pthread_join.c:89 (gdb)
Et on peut passer de l'un à l'autre:
(gdb) thread 2 [Switching to thread 2 (Thread 0x7ffff7861710 (LWP 10981))]#0 0x00000000004005ac in f () (gdb) bt #0 0x00000000004005ac in f () #1 0x00007ffff7bc98ba in start_thread (arg=) at pthread_create.c:300 #2 0x00007ffff793102d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112 #3 0x0000000000000000 in ?? () (gdb) thread 3 [Switching to thread 3 (Thread 0x7ffff7060710 (LWP 10982))]#0 0x00000000004005ac in f () (gdb) bt #0 0x00000000004005ac in f () #1 0x00007ffff7bc98ba in start_thread (arg= ) at pthread_create.c:300 #2 0x00007ffff793102d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112 #3 0x0000000000000000 in ?? () (gdb)
On peut aussi utiliser thread apply all pour aller plus vite:
(gdb) thread apply all bt Thread 3 (Thread 0x7ffff7060710 (LWP 10982)): #0 0x00000000004005ac in f () #1 0x00007ffff7bc98ba in start_thread (arg=) at pthread_create.c:300 #2 0x00007ffff793102d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112 #3 0x0000000000000000 in ?? () Thread 2 (Thread 0x7ffff7861710 (LWP 10981)): #0 0x00000000004005ac in f () #1 0x00007ffff7bc98ba in start_thread (arg= ) at pthread_create.c:300 #2 0x00007ffff793102d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112 #3 0x0000000000000000 in ?? () Thread 1 (Thread 0x7ffff7fce700 (LWP 10968)): #0 0x00007ffff7bcabe5 in pthread_join (threadid=140737346148112, thread_return=0x0) at pthread_join.c:89 #1 0x00000000004005fd in main () (gdb)
Un Heisenbug est un bug qui disparaît dès qu'on essaie de le débugguer. On a parlé plus haut du problème des options d'optimisation du compilateur. Dans le cas d'un programme multithreadé, il arrive souvent que le simple fait de lancer dans gdb fait disparaître le bug.
Soit le programme crashe, on peut utiliser le core qu'il dépose (utiliser ulimit -c unlimited si le programme n'a pas déposé de core).
$ gdb ./monprog core ...
Et on peut examiner l'ensemble du processus de la même manière que s'il était vivant, on ne peut juste pas reprendre l'exécution.
Soit le programme plante. On peut forcer la création d'un core en utilisant control-\ (c'est comme control-C, sauf que cela crée un core en plus). On peut aussi s'attacher au processus vivant:
$ gdb ./monprog $(pidof monprog) ...
Voici quelques trucs que j'utilise souvent
(gdb) l * 0x1234ou utiliser l'outil addr2line.
(gdb) p t[8]@16imprime les 16 éléments à partir de t[8]
(gdb) disp i (gdb) n (gdb) n (gdb) nla variable i est imprimée à chaque étape.
(gdb) dprintf main.c:123, "Mon i set %d\n", i (gdb) cimprimera i à chaque fois que l'exécution passe par la ligne indiquée.
€ gdb --args ./pico2wave -w test.wav foo (gdb) break main Breakpoint 1... (gdb) run Starting program Breakpoint 1, main () (gdb) record (gdb) continue ... Program received signal SIGSEGV, Segmentation fault. 0x00007ffff7711579 in picoos_deallocate (this=0x7ffff7285470, adr=0x7ffff736d100) at lib/picoos.c:579 579 if (cr->size > 0) {On récupère l'adresse de l'endroit fautif de la même façon qu'au-dessus:
(gdb) p cr $1 = (MemCellHdr) 0x8000f736f9d8 ... (gdb) p c->size $3 = 4294967296 (gdb) p &c->size $1 = (long int *) 0x7ffff736f9d8et maintenant on observe cette endroit à rebrousse-poil pour voir ce qui amène cette valeur bizarre. On doit désactiver les watchpoints matériels puisque c'est gdb qui enregistre les changements, et on peut faire un simple reverse-continue:
(gdb) set can-use-hw-watchpoints 0 (gdb) watch *(long int *) 0x7ffff736f9d8 Watchpoint 3... (gdb) reverse-continue Old value = -4294967296 New value = -1040et nous y voici ! On peut aussi utiliser reverse-next, reverse-step, etc.
(gdb) break main Breakpoint 1: ... (gdb) command 1 record continue end (gdb) break _exit Breakpoint 2: ... (gdb) command 2 run end (gdb) set pagination offOn a ici demandé à gdb de s'arrêter sur main pour activer le record, et continuer l'exécution, et de s'arrêter sur _exit (la terminaison normal du processus) pour simplement... repartir de zéro. On désactive également la pagination pour que cela tourne en rond:
(gdb) r ...va tourner jusqu'à ce qu'un segfault ou autre erreur interrompe le programme !
dl head-->next->valIl est disponible sur github.
Copyright (c) 2011-2013, 2015-2016, 2018, 2020-2021 Samuel Thibault
Ce texte est fourni sous la licence Creative Commons Attribution-ShareAlike (V3.0), ainsi que décrite sur http://creativecommons.org/licenses/by-sa/3.0/ et dont le texte complet est disponible sur http://creativecommons.org/licenses/by-sa/3.0/legalcode . Me contacter si la clause ShareAlike pose souci.