jeudi 27 janvier 2011

Projet "1 milliard" - Analyse du périmètre

Dans le cadre du challenge USI 2011, notre défi (que nous acceptons) est de développer une application pouvant accueillir 1 milliard d'utilisateurs et supportant 1 million de connexions simultanées.

Dans cet article, je délimiterai le périmètre fonctionnel de l'application. Cette première analyse permettra de mieux cadrer l'ensemble des fonctionnalités à développer.

Contexte

Le projet "1 milliard" consiste à développer une application de QCM simple. Cette application doit pouvoir accueillir jusqu'à 1 million de joueurs simultanés. Elle doit également fournir une API d'administration permettant de créer des parties, avec un ensemble de questions et les réponses associées, et d'enregistrer tous les joueurs attendus.

Notre application doit disposer de deux façades :

  • Une IHM visualisable dans un navigateur internet
  • Une API REST d'administration

Les organisateurs disposent d'un utilitaire leur permettant de tester l'API de l'application.

Fonctionnalités à développer

Ce paragraphe reprend les exigeances fonctionnelles décrites sur le site du challenge USI en rapportant les exigences à nos éléments techniques.

  • Côté API
    • La fonction "créer un utilisateur" de l'API doit supporter 1 million de requêtes en une heure
    • La fonction "créer une partie" de l'API doit attendre les informations "Questions", "Réponses", "Nombre de joueurs" et "Temps de réponse"
  • Côté API
    • Le serveur accueille tout joueur qui s'authentifie par login/mot de passe.
    • Le serveur attend la connexion de tous les joueurs avant de démarrer la partie.
    • Le serveur transmet à chaque joueur la première question.
    • Le serveur attend que tous les joueurs aient répondu ou que le temps maximum de réponse soit écoulé pour arrêter de recevoir des réponses.
    • Le serveur met à jour les scores des utilisateurs.
    • Le serveur envoie à chaque joueur la bonne réponse à la question, le score du joueur, les 100 premiers joueurs, les 50 joueurs classés avant lui et les 50 joueurs classés après.
    • Le serveur poursuit cette séquence (envoi de question, attente des réponses, calcul du score et envoi du récapitulatif) jusqu'à ce qu'il n'y ait plus de questions.

Choix d'architecture

Les choix d'architectures sont laissés à la discrétion des candidats.

Objectifs

Si les inscriptions ne sont pas encore clôturées, le nombre d'équipes maximum a déjà été atteint. Il n'est plus possible de bénéficier d'une infrastructure de test adaptée à un tel projet.

Je compte toutefois participer en candidat libre au projet. Je posterai sur ce blog mes contributions durant le challenge.

vendredi 14 janvier 2011

Guide de rédaction de journaux applicatifs

Présentation

Écrire des logs, c'est bien. Écrire des bons logs, c'est bien mieux !

Aujourd'hui, nous verrons ce qui caractérise un bon message de log, des exemples de mauvaises utilisations des journaux d'une application et des exemples de messages de log efficaces.


Introduction

Dans cet article, j'utiliserai le plus possible l'exemple suivant :
Un SI propose à ses utilisateurs de s'authentifier par leur login ou leur adresse e-mail.

Note : bien que simpliste, nous verrons que cet exemple constitue un très bon cas d'école.

L'implémentation de référence est celle-ci :

final boolean authentificated;
try {
  if(isMailAddress(username)) {
    authentificateByMail(username, password);
    authentificated = true;
  } else {
    authentificateByUsername (username, password);
    authentificated = true;
  }
} catch (AuthentificationException e) {
  authentificated = false;
} catch (Exception e) {
  e.printStackTrace();
}


Des messages pertinents

Un bon message de log peut avant tout être compris par n'importe quel développeur sans que ce dernier n'ait à lire le code source de l'application.

On trouve cependant beaucoup de messages qui ne reflètent pas un cas métier mais un état d'esprit passager du développeur passé par là. Les sites comme TheDailyWTF recensent nombre de ces exemples.

Dans notre cas, un message de log non-pertinent (impertinent ?) serait celui-ci :

} catch (Exception e) {
  log.error("It's a trap !!");
}

En un sens, cette situation est pire qu'un appel à la méthode printStackTrace() car le message de log nous masque complètement l'exception.

Ce genre de situations est d'autant plus regrettable que la correction la plus sommaire du message de log prend 2 caractères :

} catch (Exception e) {
  log.error("It's a trap !!",e);
}

Cette correction nous fait passer de "It's a trap !!" à "It's a trap !! java.net.ConnectException : connection refused".

Dit autrement, l'exploitant qui doit analyser le problème passe de "C'est incompréhensible !" à "Ok, le développeur à eu son quart d'heure de folie, en tout cas ça vient de la base de données".


Des messages clairs

L'affichage de la valeur d'une variable dans une fonction ne constitue pas une information a elle seule. Quelle frustration de consulter les logs d'un serveur et de tomber sur un message comme :
valeur=42

Dans l'idée, un tel message permet de deviner vaguement ce qui peut se passer dans l'application. Le problème, c'est que sans aller lire le code de l'application, il est impossible de l'interpréter.

Il est toujours préférable d'associer un contexte a de tels messages et donc d'indiquer les conséquences de la valeur affichée.

Revenons à notre exemple, avec un message de log peu parlant :

final boolean authentificated;
log.debug("Username : {}", username);
try {
  if(isMailAddress(username)) {
    // ...
  } else {
    // ...
  }
}
// ...

Imaginons que la méthode isMailAddress de l'exemple se contente de vérifier la présence d'un @ dans la chaîne passée en paramètre et que, quelques mois plus tard, votre client décide d'accepter les @ dans les logins des utilisateurs.

L'utilisateur 'jimC@rey' ne peut pas s'authentifier sur le système.

Avec notre message de log, nous lisons ceci :
Username = jimC@rey

Cela nous induirait presque en erreur, car ce que nous voyons n'est pas une adresse e-mail. Pourquoi diantre l'application ne se comporte-t-elle pas correctement ?

Modifions notre code pour ajouter un contexte à ce message, c'est à dire la décision qui est prise avec la valeur de "username" :

final boolean authentificated;
log.debug("Username : {}", username);
try {
  if(isMailAddress(username)) {
    log.debug("Authentification by mail address");
    // ...
  } else {
    log.debug("Authentification by username");
    // ...
  }
}
// ...

Nous lisons maintenant ceci :
Username = jimC@rey Authentification by mail address

Désormais, nous savons que l'application détecte la valeur de 'username' comme une adresse e-mail. Nous savons donc où se trouve la source de l'anomalie.


Le bon niveau de journalisation

Les differents niveaux de journalisation (debug, info, warning, error) permettent de donner plus ou moins de précisions sur une situation donnée.

Chaque niveau de log peut être utilisé à la fois pour des messages fonctionnels et techniques.

Typiquement, le niveau debug peut nous donner des informations sur chaque détail d'un traitement métier. Le niveau info nous résume ce traitement en un message. Le niveau warning nous met en évidence des cas fonctionnels maîtrisés, mais qui méritent notre attention. Le niveau error nous indique enfin l'impossibilité de réaliser un traitement et la cause de cette impossibilité.

Toujours dans notre exemple, voici ce que chaque niveau de log pourrait nous dire, au sujet d'un utilisateur 'pingtimeout' qui saisit trois fois un mot de passe incorrect.

debug : "Username : 'pingtimeout', Authentification by username"
info : "Invalid username/password for 'pingtimeout'"
warning : "Maximum connection attempts reached. The user 'pingtimeout' will be disabled for 5 minutes"
Error : "The user 'pingtimeout' is disabled. The authentification cannot be processed."

Il faut toujours garder à l'esprit que la configuration des logs n'est jamais constante. En phase de développement, on peut limiter les logs au niveau INFO et supérieurs, ou bien tous les accepter. En phase de production, on peut limiter les logs au niveau WARNING et supérieurs.

Dans tous les cas, les messages affichés doivent rester cohérents.


Des logs en guise de commentaires

L'un des avantages des logs, face aux commentaires, c'est qu'ils permettent de suivre l'état de l'application en temps réel.

Dans la partie "Des messages clairs", nous avons ajouté des logs indiquant le type d'authentification retenu. D'un point de vue documentation, il aurait été possible de mettre simplement des commentaires :

try {
  if(isMailAddress(username)) {
    // Authentification by mail address
    ...
  } else {
    // Authentification by username
    ...
  }
}

En procédant ainsi, nous n'aurions pas pu diagnostiquer notre anomalie.

Là où l'ajout de logs apporte une information pertinente, on peut se passer de commentaires. Les logs participent à la documentation du code.


Gérer son framework

En cherchant bien (sur TheDailyWtf ou ailleurs), on peut tomber sur des perles dans lesquelles un développeur, visiblement fatigué, ne maitrisait pas son framework de log. Il lui était manifestement difficile de retrouver un message en particulier dans ses journaux. Etaient-ils remplis de log.debug ? Trop verbeux ? Lui seul le sait.

En attendant, pour s'y retrouver, il a donc opté pour l'utilisation de caractères spéciaux :

log.debug("££££££££ Authentification failure !! ££££££££");

L'avantage pour lui, c'est qu'il retrouve très facilement son message grâce à un bon vieux grep. L'inconvénient pour les autres, c'est que les journaux deviennent encore moins lisibles.

Il est primordial de maitriser son framework de log. Changer le niveau de log global est simple. N'activer les traces de debug que pour quelques classes seulement est tout aussi facile.

Dans tous les cas, utiliser des caractères spéciaux pour s'y retrouver est une très mauvaise pratique !


Des éléments réutilisables

Il peut être tentant de retirer les messages de log, pour toutes sortes de raisons (lisibilité du code, idée reçue sur les performances ou juste parce qu'ils "ne seront plus utilisés"). Si vous êtes sujet à cet effet "Mr Propre", résistez !

Des logs correctement écrits ne perturbent pas la lisibilité du code, ils l'améliorent. Ce ne sont pas les responsables des dégradations de performances dont votre système souffre. Enfin, ils serviront toujours.

Si vous avez eu besoin d'un message de log à un moment donné, alors un autre développeur en aura forcement besoin dans le futur. Les messages de log d'une application ne devraient jamais être supprimés, sauf si cette suppression se fait au profit d'une réécriture plus propre.


En conclusion

Tout au long de l'article, nous avons ajouté des messages simples, sans concaténation particulière et qui viennent participer à la documentation du code. Certains messages ont d'ailleurs été ajoutés après le signalement d'un bug pour en permettre un diagnostique.

J'espère que cet article vous permettra d'écrire de meilleurs journaux applicatifs.

Vous n'écrivez pas vos logs de la même manière ? Vous avez également rencontré ces situations ? Parlons-en dans les commentaires :)

P. L.