Faire un don ! | | style | statistiques | contactez-nous | plan | lettre d'information

Journal : printf debugging considered harmful

Posté par Krunch (Jabber id, page perso, ) le 05 septembre 2006

Après avoir vainement cherché un « printf debugging considered harmful » j'en suis arrivé à la conclusion qu'il n'existait pas et j'ai donc décidé de l'écrire moi même.

J'appelle « printf debugging » le fait d'ajouter du code temporaire dans le seul but de débugger du code existant. En C, le code ajouté étant généralement un appel à printf(3) permettant par exemple de retrouver quelle partie du code a été exécutée avant le segfault dont on cherche la cause. Cette technique est particulièrement populaire chez les programmeurs débutants qui n'ont pas envie d'apprendre à se servir d'un debugger « parce qu'ils s'en passent très bien » (moi aussi j'ai dit ça à une époque). Dans ce document je tente de montrer que le printf debugging pose un certains nombre de problèmes que n'ont pas d'autres méthodes.

$ while true; do vi && make && ./plop ; done

Le premier problème le plus évident qu'on rencontre quand on pratique le printf debugging est qu'il est nécessaire de recompiler et réexécuter le code concerné plusieurs fois. En effet, on trouve rarement le bug en rajoutant un seul printf, d'où plusieurs cycles d'édition, compilation, exécution qui font perdre un temps considérable.

Le deuxième problème qui apparaît lorsque l'on a ajouté des printf un peu partout est de les retrouver tous pour les enlever une fois le bug corrigé. Ca semble trivial mais ça prend aussi du temps et il n'est pas rare d'en oublier l'un ou l'autre caché au fin fond d'une branche d'exécution qui sera prise trop rarement pour être remarqué rapidement.

Une alternative permettant d'éviter ce problème est d'utiliser un système de logging permanent (dés)activable plus ou moins dynamiquement (via une variable d'environnement, un argument ou une option de compilation par exemple) associé à un système d'assertions. De plus ça incite à écrire des messages compréhensible plutôt qu'un « toto » qui n'aura plus de signification pour personne une fois la session de debugging finie. Il existe de nombreux systèmes de logging plus ou moins complexes mais pour commencer autant s'en tenir à un simple macro qui affiche ou non son argument selon que l'on veuille afficher les logs ou non [1].

« C'est Heinsenberg qui est sur l'autoroute... » [2]

Un autre problème plus rare mais bien plus pervers est que l'ajout de code peut modifier ou masquer le bug. C'est ce qu'on appelle un heinsenbug : il devient inobservable quand on essaie d'en déterminer la nature mais réapparaît aussitôt le printf retiré. Ce genre de bug à tendance à se retrouver dans les programmes concurrents mais peut aussi être causé par de subtiles problèmes dans la gestion de la mémoire et sans doute d'autres choses. L'utilisation d'un debugger classique permet de retrouver un certains nombre de ces heinsenbugs mais pas tous.

D'autres problèmes qui peuvent sembler plus triviaux sont liés au printf debugging. Il est par exemple impossible de debugger printf lui même avec cette méthode et les systèmes de cache la rendent souvent inutile si on n'en tient pas compte.

En conclusion, le printf debugging peut être utile dans certains cas mais on rencontre vite ses limites qui peuvent être dépassées avec un usage judicieux d'un système de logging, d'assertions et d'un debugger.

À lire aussi : « Debugging 101 » [3]. Cet article déconseille l'utilisation générale de debuggers « classiques » en faveur du prinf debugging mais je persiste à penser que l'utilisation d'un système de logging et d'un debuggers plus évolués [4] reste souvent préférable. Et je suis tout à fait d'accord avec l'utilisation du « design by contract » tel qu'expliqué (ainsi qu'avec la plupart du reste de l'article).

[1] Personnellement en C99 pour des petits projets j'utilise ceci :

#ifndef NDEBUG
#  define debug(...)  fprintf(stderr, __VA_ARGS__)
#else
#  define debug(...)
#endif
Quand on développe, on compile normalement et quand on passe en « production », on définit le macro NDEBUG qui éliminera aussi les assert(3). Le macro debug() s'utilise de la même manière que printf(3) mais on le laissera dans le code final.

[2] Heinsenberg est sur l'autoroute au volant de sa voiture quand il se fait interpeller par un agent de police. « Vous savez à quelle vitesse vous rouliez ? » « Non, mais je sais où je suis » Si vous n'avez pas compris, vous devriez chercher de la documentation sur le principe d'incertitude d'Heisenberg. Je déconseille cette blague dans les soirées comportant moins de 50% de physiciens/chimistes/ingénieurs.

[3] http://www.hacknot.info/hacknot/action/showEntry?eid=85

[4] L'« Omniscient Debugger » par exemple permet de retourner en arrière dans l'exécution du code.
http://www.lambdacs.com/debugger/debugger.html
http://video.google.com/videoplay?docid=3897010229726822034

> Lire le journal (117 commentaires, moyenne: 3,4).  

Vous avez demandé le commentaire #751502.

Heisenbug...

Posté par peau chat () le 07/09/2006 à 05:42. (lien). Évalué à 3.

Voici un exemple d'Heisenbug qui ne vient pas du printf() :


[aegir@dell ~]$ cat t.c
#include <stdio.h>

int main()
{
int a=10;
printf("%d %d\n",(int)(a*.3+a*.7),(int)(10*.7+10*.3));
}
[aegir@dell ~]$ gcc -O2 t.c ; ./a.out
10 10
[aegir@dell ~]$ gcc -g3 t.c ; ./a.out
9 10
[aegir@dell ~]$


À part ça, GNU/Linux est un système parfait ;)

  • [^]Re: Heisenbug...

    Posté par Sylvain Rampacek (Jabber id, page perso, ) le 07/09/2006 à 09:53. (lien). Évalué à 2.

    visiblement, j'obtiens le même résultat avec :
    gcc -g3 t.c ; ./a.out
    et
    gcc t.c ; ./a.out
    donc je pense plutôt que ça vient d'un problème dans l'optimiseur, et pas les effets d'ajout des informations de débuggages

    • [^]Re: Heisenbug...

      Posté par peau chat () le 07/09/2006 à 10:39. (lien). Évalué à 2.

      Non, ça ne vient pas de l'optimiseur, c'est un coup de bol qu'avec -O2 on a le bon résultat (bon résultat mathématiquement parlant).

      J'ai juste voulu illustrer que, si on supprime la classique optimisation -O2 pour faire du débogage, et bien on peut voir apparaître de nouveaux bugs.

      Dans cet exemple, ce qui est "inattendu" et impévisible c'est :

      1) Le faux résultat (9 au lieu de 10)
      2) Que le faux résultat disparaisse avec l'option -O2.

      En fait, dans cet exemple, le seul truc qui se comprte de façon préfisible c'est le printf() ;-)

      [^]Re: Heisenbug...

      Posté par peau chat () le 07/09/2006 à 10:57. (lien). Évalué à 3.

      En fait c'est bel et bien un bug linux, et le problème vient de là :


      hl054353@ingvsx3j:/usr/include$ grep "FPU_DEFAULT" /usr/include/x86_64-linux/fpu_control.h
      #define _FPU_DEFAULT 0x037f


      Donc si tu transformes le code de la manière suivante :


      void set_fpu(unsigned int mode)
      {
      asm ("fldcw %0" : : "m" (*&mode));
      }


      int main(int argc, char *argv[])
      {
      set_fpu (0x27F);

      int a = 10;
      printf("%d %d\n",
      (int)( a*.3 + a*.7),
      (int)(10*.3 + 10*.7));
      return 0;
      }


      là tu auras bien les bons résultats, comme sur n'importe quel microprocesseur, ou n'importe quel autre un*x sur x86.

    [^]Re: Heisenbug...

    Posté par Sebastien Tanguy (page perso, ) le 07/09/2006 à 10:07. (lien). Évalué à 1.

    C'est vrai, la faute à Linux sans doute...


    $ uname -s ; gcc -O2 t.c ; ./a.out; gcc -g3 t.c; ./a.out
    FreeBSD
    10 10
    10 10


    Ou pas:

    % uname -s ; gcc -O2 t.c ; ./a.out; gcc -g3 t.c; ./a.out
    Linux
    10 10
    10 10

    • [^]Re: Heisenbug...

      Posté par peau chat () le 07/09/2006 à 10:34. (lien). Évalué à 2.

      Parce que ton CPU n'est pas un x86. Ou alors c'est un x86-64 et ton système est compilé en 64 bits.

      [^]Re: Heisenbug...

      Posté par lasher () le 07/09/2006 à 10:39. (lien). Évalué à 2.

      Ca vient sans doute de gcc 4.x
      J'ai testé sur une debian testing, avec gcc 4.0 et 4.1 : bug ;
      Sur une red hat customisée : gcc 3.2.3, puis un gcc pré version 4 (gcc-ssa) : ça marche. Idem avec gcc 2.96.

      En fait, avec gcc 4, il faut lancer l'optimisation pour que ça marche correctement .

      • [^]Re: Heisenbug...

        Posté par peau chat () le 07/09/2006 à 10:43. (lien). Évalué à 2.

        Euh, c'est quoi que tu appelles "ça marche correctement" ?

        Normalement, dans tous les cas, ça doit afficher "10 10".

        Ca n'affiche "9 10" que si :

        1) Tu es sur cpu x86
        2) Tu es sous un Linux compilé en 32 bits.

        Sur un BSD sur x86 cela affichera toujours le résultat correct "10 10".

    [^]Re: Heisenbug...

    Posté par Troy McClure (page perso, ) le 07/09/2006 à 10:32. (lien). Évalué à 0.

    probleme d'arrondi classique avec les floats, dans un cas ça donne 9.999999999 et dans l'autre 10.0000000001 , quand tu tronques les decimales paf c'est le désastre. Mais je te trouve gonflé d'accusé linux :)

    • [^]Re: Heisenbug...

      Posté par peau chat () le 07/09/2006 à 10:45. (lien). Évalué à 1.

      Ah ? Et tu trouves donc normal que 9,99999999 soit arrondi à 9 lors de la conversion en entier ?

      Arrondir, ce n'est pas tronquer les décimales.

      Enfin, en tout cas, d'après les normes IEEE ça ne devrait pas.

      • [+] [^]Re: Heisenbug...

        Posté par Troy McClure (page perso, ) le 07/09/2006 à 10:58. (lien). Évalué à -2.

        ah mais où est-ce que tu arrondis ? (int)(0.9) ça a toujours donné 0 , ça n'arrondi pas!

        • [^]Re: Heisenbug...

          Posté par peau chat () le 07/09/2006 à 11:14. (lien). Évalué à 1.

          Ce n'est pas le (int) qui fait l'arrondi, c'est l'expression mathématique.

          Et heureusement !

          int i = (int) (100 * 0.1);

          peut contenir 9 ???

          Ou alors encore mieux :

          int a = (int) (100 *2); // donne 200
          int b = (int) (100 *2.0); // donne 199

          ????

          Heureusement que non, sinon il y aurait beaucoup plus de bugs ;)

          D'après la norme IEEE754 :

          "Unbiased which rounds to the nearest value, if the number falls midway it is rounded to the nearest value with an even (zero) least significant bit. This mode is required to be default."

    [^]Re: Heisenbug...

    Posté par Jean-Philippe Garcia Ballester (Jabber id, page perso, ) le 07/09/2006 à 10:52. (lien). Évalué à 2.

    Si mes souvenirs sont bons, c'est une histoire de taille différente entre registre et mémoire, et qu'un passage de l'un à l'autre tronque le flottant.

    • [^]Re: Heisenbug...

      Posté par peau chat () le 07/09/2006 à 11:01. (lien). Évalué à 3.

      Et comment expliquerais tu alors que sur le même microprocesseur, le mêmecode compilé avec le même mricroprocesseur donne "9 10" sous Linux et "10 10" sous BSD. ;)

      C'est un problème que Linux d'initialise pas le FPU comme il faut. C'est connu depuis longtemps.

      • [^]Re: Heisenbug...

        Posté par miod () le 15/09/2006 à 15:49. (lien). Évalué à 1.

        On ne peut pas dire que Linux n'initialise pas les paramètres IEEE754 "comme il faut". Aucune norme n'impose qu'un programme démarre dans un mode spécifique

        C'est au programmeur de paramétrer le mode d'arrondi dont il a besoin, s'il veut avoir des résultats reproductibles.

        De façon portable, cela se fait avec fpsetround().