Niveau :      

Savoir relire le code d'un autre est indispensable. Et ce pour plusieurs raisons, soit parce que vous voulez vous mettre à travailler sur un projet existant, soit parce que vous voulez simplement fournir un patch pour un code qu'on vous a fourni (probablement open source). Nous allons donc voir de quoi il s'agit, puis mettre en pratique sur apache.

Pour vous lancer dans l'aventure, il peut vous être utile de savoir utiliser ctags ou etags. De plus, connaître des techniques de lecture rapide vous permettra d'aller plus vite.

Plantons le décor, nous voulons faire un patch à apache 2.2 pour permettre d'ajouter dans les logs les durées de récupération de données par mod_proxy. Récupérons le code source et partons de ce qu'on sait (et n'oublions pas de le dupliquer pour nous simplifier la création de patch par la suite).

$ cp -a apache2-2.2.6 apache2-2.2.6.old
$ cd apache2-2.2.6
$ find . -type f | grep "c$" | xargs ctags

On sait qu'actuellement, grâce à mod_log_config, on peut logguer les durées individuelles des requêtes. Le code source semble divisé logiquement, nous allons donc lire modules/loggers/mod_log_config.c. Parcourons-le rapidement, on constate un certain nombre de fonctions log_*, probablement pour écrire dans les logs. Étant donné la façon dont elles sont appelées, il doit y avoir une référence dans un tableau quelque part. On la trouve en fin de fichier, ainsi que la fonction qui nous intéresse : log_request_duration_microseconds.

Lisons-la :

$ vi -t log_request_duration_microseconds

Deux choses intéressantes :

  • apr_time_now() -> au vu du nom et de la précision, ça doit donner la date et l'heure en microsecondes. Donc on sait comment on va calculer notre durée.
  • r->request_time et request_rec *r -> on en déduit qu'il existe une structure par requête dans laquelle on pourra stocker les dates de début et de fin.

Cherchons maintenant où appeler ces fonctions pour calculer les durées. Nous allons donc lire ./modules/proxy/mod_proxy.c. On le parcourt en largeur et on constate que :

  • C'est plutôt bien commenté
  • Les noms de fonction ont un sens
  • La majorité des fonctions s'appelle proxy_*

On prend la liste de ces fonctions et au vu des noms, proxy_handler est celle qui a le plus de chance de nous intéresser. À la lecture de la fonction, on voit que le début n'appelle pas de fonction non standard ayant un sens (en gros ap_die et ap_finalize_request_protocol) on saute donc jusqu'à :

    do {
        char *url = uri;
        /* Try to obtain the most suitable worker */

Ça commence à nous intéresser. À l'intérieur on trouve enfin quelque chose d'utile :

        /* handle the scheme */
        ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, r->server,
                     "Running scheme %s handler (attempt %d)",
                     scheme, attempts);
        access_status = proxy_run_scheme_handler(r, worker, conf,
                                                 url, NULL, 0);

Et voila, on a trouvé ce qui nous intéressait vraiment. Pour preuve : ...

Et pour ceux qui veulent savoir, la fonction appelée derrière dans le cas de mod_proxy_http est proxy_http_handler, qu'on trouve cette fois beaucoup plus facilement à la lecture de ./modules/proxy/mod_proxy_http.c.

On placera donc nos appels à apr_time_now() juste avant et après cette fonction.

Avant de placer l'appel, il faut préparer la structure qui hébergera l'information. On a vu qu'on pourrait la mettre dans request_rec, heureusement on voit que les données relatives à la requête sont disponibles dans notre fonction sous cette forme. Allons y mettre notre information :

$ vi -t request_rec

On ajoute 2 champs, qu'on copie d'un champ qu'on connaît et qui a déjà le bon type : request_time

    /** Time when the proxy request started */
    apr_time_t proxy_begin;
    /** Time when the proxy request stopped */
    apr_time_t proxy_end;

Et ajoutons nos 2 lignes

        r->proxy_begin = apr_time_now();
        access_status = proxy_run_scheme_handler(r, worker, conf,
                                                 url, NULL, 0);
        r->proxy_end = apr_time_now();

Et enfin, on ajoute au module de log la possibilité de logguer tout ceci sur un code non occupé : choisissons %W

Et voila, c'est fini, ou presque. Il ne reste plus qu'à

  • Créer le patch : diff -ru apache2-2.2.6.old apache2-2.2.6
  • Recompiler
  • Tester
  • Envoyer à l'auteur

PS : Vous trouverez 2 patchs en pièce jointe, le premier ne patche que mod_proxy_http car je l'ai trouvé plus facile à lire au premier abord. Le second correspond au texte de l'article. Cf les annexes ci-dessous.