Variations sur un log

Supposons que nous ne voulons plus seulement enregistrer les logs vers un fichier. Nous pourrions vouloir les afficher à l'écran, les envoyer au daemon syslog d'Unix(tm) via un socket. Comment s'accommoder de tels changements ?

Le plus simple est de créer des sous-classes de Log qui écrasent la méthode message() avec les nouvelles versions. Ce système fonctionne bien à court terme, sauf qu'il a quelque chose de subtilement mais foncièrement erroné. Supposons que nous créions ces sous-classes et que nous ayons des loggueurs écrivant vers un fichier, sur l'écran et via le réseau. Trois classes en tout : ça fonctionne. Maintenant supposons que nous voulons ajouter une nouvelle classe de log qui ajoute un filtrage par priorité des messages, ne laissant passer que les messages d'un certain type, le tout suivant un fichier de configuration.

Nous sommes coincés. Si nous créons de nouvelles sous-classes, nous devons le faire pour l'ensemble des trois classes, ce qui nous donnerait six classes. L'envergure de la duplication est horrible.

Alors, est-ce que vous êtes en train de souhaiter que PHP ait l'héritage multiple ? Effectivement, cela réduirait l'ampleur de la tâche à court terme, mais aussi compliquerait quelque chose qui devrait être une classe très simple. L'héritage multiple, même supporté, devrait être utilisé avec le plus grand soin car toutes sortes d'enchevêtrements peuvent en découler. En fait ce soudain besoin nous dit quelque chose d'autre - peut-être que notre erreur si situe au niveau de la conception.

Qu'est-ce que doit faire un loggueur ? Est-ce qu'il envoie un message vers un fichier ? A l'écran ? Via le réseau ? Non. Il envoie un message, point final. La cible de ses messages peut être sélectionnée à l'initialisation du log, mais après ça pas touche : le loggueur doit pouvoir combiner et formater les éléments du message puisque tel est son véritable boulot. Présumer que la cible fut un nom de fichier était une belle paire d'oeillères.

Abstraire un fichier vers un scripteur

La solution de cette mauvaise passe est un classique. Tout d'abord nous encapsulons la variation de la classe : cela ajoute un niveau d'indirection. Au lieu d'introduire le nom du fichier comme une chaîne, nous l'introduisons comme "cette chose vers laquelle on écrit" et que nous appelons un Writer. Retour aux tests...

<?php
    require_once('../classes/log.php');
    require_once('../classes/clock.php');
    require_once('../classes/writer.php');
    Mock::generate('Clock');

    class TestOfLogging extends UnitTestCase {
        function TestOfLogging() {
            $this->UnitTestCase('Log class test');
        }
        function setUp() {
            @unlink('../temp/test.log');
        }
        function tearDown() {
            @unlink('../temp/test.log');
        }
        function getFileLine($filename, $index) {
            $messages = file($filename);
            return $messages[$index];
        }
        function testCreatingNewFile() {
            $log = new Log(new FileWriter('../temp/test.log'));
            $this->assertFalse(file_exists('../temp/test.log'), 'Created before message');
            $log->message('Should write this to a file');
            $this->assertTrue(file_exists('../temp/test.log'), 'File created');
        }
        function testAppendingToFile() {
            $log = new Log(new FileWriter('../temp/test.log'));
            $log->message('Test line 1');
            $this->assertWantedPattern(
                    '/Test line 1/',
                    $this->getFileLine('../temp/test.log', 0));
            $log->message('Test line 2');
            $this->assertWantedPattern(
                    '/Test line 2/',
                    $this->getFileLine('../temp/test.log', 1));
        }
        function testTimestamps() {
            $clock = &new MockClock($this);
            $clock->setReturnValue('now', 'Timestamp');
            $log = new Log(new FileWriter('../temp/test.log'));
            $log->message('Test line', &$clock);
            $this->assertWantedPattern(
                    '/Timestamp/',
                    $this->getFileLine('../temp/test.log', 0),
                    'Found timestamp');
        }
    }
?>

Nous pourrions, mais ce n'est pas obligé. Par contre nous avons besoin de créer l'interface, ou alors il ne sera pas possible de la simuler. Au final classes/writer.php ressemble à...

<?php
    class FileWriter {
        
        function FileWriter($file_path) {
        }
        
        function write($message) {
        }
    }
?>

<?php
    require_once('../classes/clock.php');
    require_once('../classes/writer.php');
    
    class Log {
        var $_writer;
        
        function Log(&$writer) {
            $this->_writer = &$writer;
        }
        
        function message($message, $clock = false) {
            if (! is_object($clock)) {
                $clock = new Clock();
            }
            $this->_writer->write("[" . $clock->now() . "] $message");
        }
    }
?>

Nous pourrions commencer par écrire des tests et développer la classe FileWriter parallèlement, mais lors de cette étape nos tests de Log continueraient d'échouer et de nous distraire. En fait nous n'en avons pas besoin.

Une partie de notre objectif est de libérer la classe du loggueur de l'emprise du système de fichiers et il existe un moyen d'y arriver. Tout d'abord nous créons le fichier tests/writer_test.php de manière à avoir un endroit pour placer notre code test en provenance de log_test.php et que nous allons brasser. Sauf que je ne vais pas l'ajouter dans le fichier all_tests.php pour l'instant puisque qu'il s'agit de la partie de log que nous sommes en train d'aborder.

Nous enlevons tous les test de log_test.php qui ne sont pas strictement en lien avec le journal et nous les gardons bien précieusement dans writer_test.php pour plus tard. Nous allons aussi simuler le scripteur pour qu'il n'écrive pas réellement dans un fichier...

<?php
    require_once('../classes/log.php');
    require_once('../classes/clock.php');
    require_once('../classes/writer.php');
    Mock::generate('Clock');
    Mock::generate('FileWriter');

    class TestOfLogging extends UnitTestCase {
        function TestOfLogging() {
            $this->UnitTestCase('Log class test');
        }
        function testWriting() {
            $clock = &new MockClock($this);
            $clock->setReturnValue('now', 'Timestamp');
            $writer = &new MockFileWriter($this);
            $writer->expectArguments('write', array('[Timestamp] Test line'));
            $writer->expectCallCount('write', 1);
            $log = &new Log($writer);
            $log->message('Test line', &$clock);
            $writer->tally();
        }
    }
?>

1. La nécessité de créer le fichier uniquement si nécessaire a été déplacée vers le FileWriter.
2. Étant donné que nous travaillons avec des objets fantaisie, aucun fichier n'a été créé et donc setUp() et tearDown() passent dans les tests du scripteur.
3. Désormais le test consiste simplement dans l'envoi d'un message type et du test de son format.

Les objets fantaisie font beaucoup plus que se comporter comme des objets, ils exécutent aussi des test. L'appel expectArguments() dit à l'objet fantaisie d'attendre un seul paramètre de la chaîne "[Timestamp] Test" quand la méthode fantaise write() est appelée. Lorsque cette méthode est appelée les paramètres attendus sont comparés avec ceci et un succès ou un échec est renvoyé comme résultat au test unitaire. C'est pourquoi un nouvel objet fantaisie a une référence vers $this dans son constructeur, il a besoin de ce $this pour l'envoi de son propre résultat.

L'autre attente, c'est que le write ne soit appelé qu'une seule et unique fois. Juste l'initialiser ne serait pas suffisant. L'objet fantaisie attendrait une éternité si la méthode n'était jamais appelée et par conséquent n'enverrait jamais le message d'erreur à la fin du test. Pour y faire face, l'appel tally() lui dit de vérifier le nombre d'appel à ce moment là. Nous pouvons voir tout ça en lançant les tests...

En fait nous pouvons encore raccourcir nos tests. L'attente de l'objet fantaisie expectOnce() peut combiner les deux attentes séparées.

function testWriting() {
    $clock = &new MockClock($this);
    $clock->setReturnValue('now', 'Timestamp');
    $writer = &new MockFileWriter($this);
    $writer->expectOnce('write', array('[Timestamp] Test line'));
    $log = &new Log($writer);
    $log->message('Test line', &$clock);
    $writer->tally();
}

Classes frontières

Quelque chose de très agréable est arrivée au loggueur en plus de devenir purement et simplement plus court.

Les seules choses dont il dépend sont maintenant des classes que nous avons écrites nous-même et qui dans les tests sont simulées : donc aucune dépendance hormis notre propre code PHP. Pas de fichier à écrire ni de déclenchement via une horloge à attendre. Cela veut dire que le scénario de test log_test.php va s'exécuter aussi vite que le processeur le permet. Par contraste les classes FileWriter et Clock sont très proches du système. Plus difficile à tester puisque de vraies données doivent être déplacées et validées avec soin, souvent par des astuces ad hoc.

Notre dernière factorisation a beaucoup aidé. Les classes aux frontières de l'application et du système, celles qui sont difficiles à tester, sont désormais plus courtes étant donné que le code d'I/O a été éloigné encore plus de la logique applicative. Il existe des liens directs vers des opérations PHP : FileWriter::write() s'apparente à l'équivalent PHP fwrite() avec le fichier ouvert pour l'ajout et Clock::now() s'apparente lui aussi à un équivalent PHP time(). Primo le débogage devient plus simple. Secundo ces classes devraient bouger moins souvent.