Tirer le meilleur parti de vos fichiers journaux PHP : un guide pratique

On pourrait dire à juste titre que les journaux sont l'un des outils les plus sous-estimés et sous-utilisés à la disposition d'un développeur php indépendant. Malgré la richesse des informations qu'ils peuvent offrir, il n'est pas rare que les journaux soient le dernier endroit où un développeur consulte lorsqu'il tente de résoudre un problème.

En vérité, les fichiers journaux PHP devraient dans de nombreux cas être le premier endroit où rechercher des indices lorsque des problèmes surviennent. Souvent, les informations qu'ils contiennent peuvent réduire considérablement le temps passé à vous arracher les cheveux à essayer de traquer un bogue épineux.

Mais peut-être plus important encore, avec un peu de créativité et de prévoyance, vos fichiers journaux peuvent être exploités pour servir de source précieuse d'informations et d'analyses d'utilisation. L'utilisation créative des fichiers journaux peut aider à répondre à des questions telles que : Quels sont les navigateurs les plus couramment utilisés pour visiter mon site ? Quel est le temps de réponse moyen de mon serveur ? Quel était le pourcentage de requêtes à la racine du site ? Comment l'utilisation a-t-elle changé depuis que nous avons déployé les dernières mises à jour ? Et bien plus encore.

Cet article fournit un certain nombre de conseils sur la façon de configurer vos fichiers journaux, ainsi que sur la façon de traiter les informations qu'ils contiennent, afin d'optimiser les avantages qu'ils procurent.

Bien que cet article se concentre techniquement sur la journalisation pour les développeurs PHP, la plupart des informations présentées ici sont assez indépendantes de la technologie et sont également pertinentes pour d'autres langages et piles technologiques.

Remarque : cet article suppose une connaissance de base du shell Unix. Pour ceux qui n'ont pas ces connaissances, une annexe est fournie qui présente certaines des commandes nécessaires pour accéder et lire les fichiers journaux sur un système Unix.

Notre projet d'exemple de fichier journal PHP

Comme exemple de projet à des fins de discussion dans cet article, nous prendrons Symfony Standard comme projet de travail et nous le configurerons sur Debian 7 Wheezy avec rsyslogd , nginx et PHP-FPM .

 composer create-project symfony/framework-standard-edition my "2.6.*"

Cela nous donne rapidement un projet de test fonctionnel avec une belle interface utilisateur.

Conseils pour configurer vos fichiers journaux

Voici quelques conseils sur la façon de configurer vos fichiers journaux pour aider à maximiser leur valeur.

Configuration du journal des erreurs

Les journaux d'erreurs représentent la forme de journalisation la plus élémentaire ; c'est-à-dire, capturer des informations et des détails supplémentaires lorsque des problèmes surviennent. Ainsi, dans un monde idéal, vous voudriez qu'il n'y ait pas d'erreurs et que vos journaux d'erreurs soient vides. Mais lorsque des problèmes surviennent (comme ils le font invariablement), vos journaux d'erreurs doivent être l'un des premiers arrêts que vous effectuez sur votre piste de débogage.

Les journaux d'erreurs sont généralement assez faciles à configurer.

D'une part, tous les messages d'erreur et de plantage peuvent être consignés dans le journal des erreurs exactement dans le même format dans lequel ils seraient autrement présentés à un utilisateur. Avec une configuration simple, l'utilisateur final n'aura jamais besoin de voir ces affreuses traces d'erreur sur votre site, tandis que devops pourra toujours surveiller le système et examiner ces messages d'erreur dans tous leurs détails sanglants. Voici comment configurer ce type de journalisation en PHP :

 log_errors = On error_reporting = E_ALL error_log = /path/to/my/error/log

Deux autres lignes qu'il est important d'inclure dans un fichier journal pour un site en ligne, afin d'éviter que des niveaux sanglants de détails d'erreur ne soient présentés aux utilisateurs, sont :

 display_errors = Off display_startup_errors = Off

Configuration du journal système ( syslog )

Il existe de nombreuses implémentations généralement compatibles du démon syslog dans le monde open source, notamment :

• syslogd et sysklogd - le plus souvent vus sur les systèmes de la famille BSD, CentOS, Mac OS X et autres
• syslog-ng - par défaut pour les versions modernes de Gentoo et SuSE
• rsyslogd - largement utilisé sur les familles de systèmes d'exploitation Debian et Fedora

(Remarque : dans cet article, nous utiliserons rsyslogd pour nos exemples.)

La configuration de base de syslog est généralement adéquate pour capturer vos messages de journal dans un fichier journal à l'échelle du système (normalement /var/log/syslog ; peut également être /var/log/messages ou /var/log/system.log selon la distribution vous utilisez).

Le journal système fournit plusieurs fonctionnalités de journal, dont huit ( LOG_LOCAL0 à LOG_LOCAL7 ) sont réservées aux projets déployés par l'utilisateur. Voici, par exemple, comment configurer LOG_LOCAL0 pour écrire dans 4 fichiers journaux distincts, en fonction du niveau de journalisation (c'est-à-dire, erreur, avertissement, info, débogage) :

 # /etc/rsyslog.d/my.conf local0.err /var/log/my/err.log local0.warning /var/log/my/warning.log local0.info -/var/log/my/info.log local0.debug -/var/log/my/debug.log

Désormais, chaque fois que vous écrivez un message de journal dans la LOG_LOCAL0 , les messages d'erreur iront à /var/log/my/err.log , les messages d'avertissement iront à /var/log/my/warning.log , etc. Notez cependant que le démon syslog filtre les messages pour chaque fichier en fonction de la règle « ce niveau et supérieur ». Ainsi, dans l'exemple ci-dessus, tous les messages d'erreur apparaîtront dans les quatre fichiers configurés, les messages d'avertissement apparaîtront dans tous sauf le journal des erreurs, les messages d'information apparaîtront dans les journaux d'information et de débogage, et les messages de débogage n'iront qu'à debug.log .

Une note importante supplémentaire ; Les signes - avant les fichiers d'information et de niveau de débogage dans l'exemple de fichier de configuration ci-dessus indiquent que les écritures dans ces fichiers doivent être effectuées de manière asynchrone (puisque ces opérations ne sont pas bloquantes). C'est généralement bien (et même recommandé dans la plupart des situations) pour les journaux d'informations et de débogage, mais il est préférable que les écritures dans le journal des erreurs (et probablement aussi dans le journal des avertissements) soient synchrones.

Afin d'arrêter un niveau de journalisation moins important (par exemple, sur un serveur de production), vous pouvez simplement rediriger les messages associés vers /dev/null (c'est-à-dire vers nulle part) :

 local0.debug /dev/null # -/var/log/my/debug.log

Une personnalisation spécifique utile, en particulier pour prendre en charge une partie de l'analyse des fichiers journaux PHP dont nous parlerons plus loin dans cet article, consiste à utiliser la tabulation comme caractère délimiteur dans les messages de journal. Cela peut facilement être fait en ajoutant le fichier suivant dans /etc/rsyslog.d :

 # /etc/rsyslog.d/fixtab.conf $EscapeControlCharactersOnReceive off

Et enfin, n'oubliez pas de redémarrer le démon syslog après avoir apporté des modifications à la configuration afin qu'elles prennent effet :

 service rsyslog restart

Configuration du journal du serveur

Contrairement aux journaux d'application et aux journaux d'erreurs dans lesquels vous pouvez écrire, les journaux de serveur sont exclusivement écrits par les démons de serveur correspondants (par exemple, serveur Web, serveur de base de données, etc.) à chaque requête. Le seul "contrôle" que vous avez sur ces journaux est dans la mesure où le serveur vous permet de configurer sa fonctionnalité de journalisation. Bien qu'il puisse y avoir beaucoup à parcourir dans ces fichiers, ils sont souvent le seul moyen d'avoir une idée claire de ce qui se passe « sous le capot » avec votre serveur.

Déployons notre exemple d'application Symfony Standard sur l'environnement nginx avec le backend de stockage MySQL. Voici la configuration de l'hôte nginx que nous utiliserons :

 server { server_name my.log-sandbox; root /var/www/my/web; location / { # try to serve file directly, fallback to app.php try_files $uri /app.php$is_args$args; } # DEV # This rule should only be placed on your development environment # In production, don't include this and don't deploy app_dev.php or config.php location ~ ^/(app_dev|config)\.php(/|$) { fastcgi_pass unix:/var/run/php5-fpm.sock; fastcgi_split_path_info ^(.+\.php)(/.*)$; include fastcgi_params; fastcgi_param SCRIPT_FILENAME $document_root$fastcgi_script_name; fastcgi_param HTTPS off; } # PROD location ~ ^/app\.php(/|$) { fastcgi_pass unix:/var/run/php5-fpm.sock; fastcgi_split_path_info ^(.+\.php)(/.*)$; include fastcgi_params; fastcgi_param SCRIPT_FILENAME $document_root$fastcgi_script_name; fastcgi_param HTTPS off; # Prevents URIs that include the front controller. This will 404: # http://domain.tld/app.php/some-path # Remove the internal directive to allow URIs like this internal; } error_log /var/log/nginx/my_error.log; access_log /var/log/nginx/my_access.log; }

En ce qui concerne les deux dernières directives ci-dessus : access_log représente le journal général des requêtes, tandis que error_log est pour les erreurs, et, comme pour les journaux d'erreurs d'application, il vaut la peine de configurer une surveillance supplémentaire pour être alerté des problèmes afin que vous puissiez réagir rapidement.

Remarque : il s'agit d'un fichier de configuration nginx intentionnellement simplifié qui est fourni à titre d'exemple uniquement. Il n'accorde presque aucune attention à la sécurité et aux performances et ne doit pas être utilisé tel quel dans un environnement "réel".

C'est ce que nous obtenons dans /var/log/nginx/my_access.log après avoir tapé http://my.log-sandbox/app_dev.php/ dans le navigateur et appuyé sur Enter .

 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /app_dev.php/ HTTP/1.1" 200 6715 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/framework/css/body.css HTTP/1.1" 200 6657 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/framework/css/structure.css HTTP/1.1" 200 1191 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/acmedemo/css/demo.css HTTP/1.1" 200 2204 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/acmedemo/images/welcome-quick-tour.gif HTTP/1.1" 200 4770 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/acmedemo/images/welcome-demo.gif HTTP/1.1" 200 4053 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/acmedemo/images/welcome-configure.gif HTTP/1.1" 200 3530 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /favicon.ico HTTP/1.1" 200 6518 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:30 +0300] "GET /app_dev.php/_wdt/e50d73 HTTP/1.1" 200 13265 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36"

Cela montre que, pour servir une page, le navigateur effectue en fait 9 appels HTTP. 7 d'entre eux, cependant, sont des demandes de contenu statique, qui sont simples et légers. Cependant, ils consomment toujours des ressources réseau et c'est ce qui peut être optimisé en utilisant divers sprites et techniques de minification.

Bien que ces optimisations soient discutées dans un autre article, ce qui est pertinent ici, c'est que nous pouvons enregistrer les requêtes vers des contenus statiques séparément en utilisant une autre directive de location pour celles-ci :

 location ~ \.(jpg|jpeg|gif|png|ico|css|zip|tgz|gz|rar|bz2|pdf|txt|tar|wav|bmp|rtf|js)$ { access_log /var/log/nginx/my_access-static.log; }

N'oubliez pas que l' location nginx effectue une simple correspondance d'expressions régulières, vous pouvez donc inclure autant d'extensions de contenu statique que vous prévoyez d'envoyer sur votre site.

L'analyse de ces journaux n'est pas différente de l'analyse des journaux d'application.

Autres journaux à mentionner

Deux autres journaux PHP qui méritent d'être mentionnés sont le journal de débogage et le journal de stockage des données.

Le journal de débogage

Une autre chose pratique à propos des journaux nginx est le journal de débogage. Nous pouvons l'activer en remplaçant la ligne error_log de la configuration par ce qui suit (nécessite que le module de débogage nginx soit installé) :

 error_log /var/log/nginx/my_error.log debug;

Le même paramètre s'applique à Apache ou à tout autre serveur Web que vous utilisez.

Et accessoirement, les journaux de débogage ne sont pas liés aux journaux d'erreurs, même s'ils sont configurés dans la directive error_log .

Bien que le journal de débogage puisse en effet être verbeux (une seule requête nginx, par exemple, a généré 127 Ko de données de journal !), il peut toujours être très utile. Parcourir un fichier journal peut être lourd et fastidieux, mais il peut souvent fournir rapidement des indices et des informations qui aident grandement à accélérer le processus de débogage.

En particulier, le journal de débogage peut vraiment aider au débogage des configurations nginx, en particulier les parties les plus compliquées, comme la correspondance d' location et les chaînes de rewrite .

Bien entendu, les journaux de débogage ne doivent jamais être activés dans un environnement de production. La quantité d'espace qu'ils utilisent également et la quantité d'informations qu'ils stockent signifient beaucoup de charge d'E/S sur votre serveur, ce qui peut dégrader considérablement les performances de l'ensemble du système.

Journaux de stockage de données

Un autre type de journal de serveur (utile pour le débogage) est les journaux de stockage de données. Dans MySQL, vous pouvez les activer en ajoutant ces lignes :

 [mysqld] general_log = 1 general_log_file = /var/log/mysql/query.log

Ces journaux contiennent simplement une liste de requêtes exécutées par le système lors du traitement des demandes de base de données dans l'ordre chronologique, ce qui peut être utile pour divers besoins de débogage et de traçage. Cependant, ils ne doivent pas rester activés sur les systèmes de production, car ils généreront une charge d'E/S supplémentaire inutile, ce qui affectera les performances.

Écrire dans vos fichiers journaux

PHP lui-même fournit des fonctions pour ouvrir, écrire et fermer les fichiers journaux ( openlog() , syslog() et closelog() ).

Il existe également de nombreuses bibliothèques de journalisation pour le développeur PHP, telles que Monolog (populaire parmi les utilisateurs de Symfony et Laravel), ainsi que diverses implémentations spécifiques au framework, telles que les capacités de journalisation intégrées à CakePHP. En général, les bibliothèques comme Monolog enveloppent non seulement les appels syslog() , mais permettent également d'utiliser d'autres fonctionnalités et outils backend.

Voici un exemple simple d'écriture dans le journal :

 <?php openlog(uniqid(), LOG_ODELAY, LOG_LOCAL0); syslog(LOG_INFO, 'It works!');

Notre appel ici à openlog :

• configure PHP pour ajouter un identifiant unique à chaque message du journal système pendant la durée de vie du script
• le définit pour retarder l'ouverture de la connexion syslog jusqu'à ce que le premier appel syslog() se soit produit
• définit LOG_LOCAL0 comme fonction de journalisation par défaut

Voici à quoi ressemblerait le contenu du fichier journal après avoir exécuté le code ci-dessus :

 # cat /var/log/my/info.log Mar 2 00:23:29 log-sandbox 54f39161a2e55: It works!

Maximiser la valeur de vos fichiers journaux PHP

Maintenant que nous sommes tous bons avec la théorie et les bases, voyons ce que nous pouvons obtenir des journaux en apportant le moins de modifications possible à notre exemple de projet Symfony Standard.

Tout d'abord, créons les scripts src/log-begin.php (pour ouvrir et configurer correctement nos journaux) et src/log-end.php (pour enregistrer les informations sur la réussite). Notez que, pour plus de simplicité, nous allons simplement écrire tous les messages dans le journal d'informations.

 # src/log-begin.php <?php define('START_TIME', microtime(true)); openlog(uniqid(), LOG_ODELAY, LOG_LOCAL0); syslog(LOG_INFO, 'BEGIN'); syslog(LOG_INFO, "URI\t{$_SERVER['REQUEST_URI']}"); $browserHash = substr(md5($_SERVER['HTTP_USER_AGENT']), 0, 7); syslog(LOG_INFO, "CLIENT\t{$_SERVER['REMOTE_ADDR']}\t{$browserHash}"); <br /> # src/log-end.php <?php syslog(LOG_INFO, "DISPATCH TIME\t" . round(microtime(true) - START_TIME, 2)); syslog(LOG_INFO, 'END');

Et exigeons ces scripts dans app.php :

 <?php require_once(dirname(__DIR__) . '/src/log-begin.php'); syslog(LOG_INFO, "MODE\tPROD"); # original app.php contents require_once(dirname(__DIR__) . '/src/log-end.php');

Pour l'environnement de développement, nous souhaitons également exiger ces scripts dans app_dev.php . Le code pour le faire serait le même que ci-dessus, sauf que nous définirions le MODE sur DEV plutôt que sur PROD .

Nous voulons également suivre les contrôleurs invoqués, alors ajoutons une ligne supplémentaire dans Acme\DemoBundle\EventListener\ControllerListener , juste au début de la méthode ControllerListener::onKernelController() :

 syslog(LOG_INFO, "CONTROLLER\t" . get_class($event->getController()[0]));

Notez que ces modifications ne totalisent que 15 lignes de code supplémentaires, mais peuvent collectivement fournir une mine d'informations.

Analyse des données dans vos fichiers journaux

Pour commencer, voyons combien de requêtes HTTP sont nécessaires pour servir chaque chargement de page.

Voici les informations contenues dans les journaux pour une requête, en fonction de la manière dont nous avons configuré notre journalisation :

 Mar 3 12:04:20 log-sandbox 54f58724b1ccc: BEGIN Mar 3 12:04:20 log-sandbox 54f58724b1ccc: URI /app_dev.php/ Mar 3 12:04:20 log-sandbox 54f58724b1ccc: CLIENT 192.168.56.1 1b101cd Mar 3 12:04:20 log-sandbox 54f58724b1ccc: MODE DEV Mar 3 12:04:23 log-sandbox 54f58724b1ccc: CONTROLLER Acme\DemoBundle\Controller\WelcomeController Mar 3 12:04:25 log-sandbox 54f58724b1ccc: DISPATCH TIME 4.51 Mar 3 12:04:25 log-sandbox 54f58724b1ccc: END Mar 3 12:04:25 log-sandbox 54f5872967dea: BEGIN Mar 3 12:04:25 log-sandbox 54f5872967dea: URI /app_dev.php/_wdt/59b8b6 Mar 3 12:04:25 log-sandbox 54f5872967dea: CLIENT 192.168.56.1 1b101cd Mar 3 12:04:25 log-sandbox 54f5872967dea: MODE DEV Mar 3 12:04:28 log-sandbox 54f5872967dea: CONTROLLER Symfony\Bundle\WebProfilerBundle\Controller\ProfilerController Mar 3 12:04:29 log-sandbox 54f5872967dea: DISPATCH TIME 4.17 Mar 3 12:04:29 log-sandbox 54f5872967dea: END

Nous savons donc maintenant que chaque chargement de page est en fait servi avec deux requêtes HTTP.

En fait, il y a deux points qui méritent d'être mentionnés ici. Tout d'abord, les deux requêtes par chargement de page concernent l'utilisation de Symfony en mode dev (ce que j'ai fait tout au long de cet article). Vous pouvez identifier les appels du mode de développement en recherchant les blocs d'URL /app-dev.php/ . Deuxièmement, disons que chaque chargement de page est servi avec deux requêtes ultérieures à l'application Symfony. Comme nous l'avons vu précédemment dans les journaux d'accès nginx, il y a en fait plus d'appels HTTP, dont certains sont destinés au contenu statique.

OK, maintenant surfons un peu sur le site de démonstration (pour construire les données dans les fichiers journaux) et voyons ce que nous pouvons apprendre d'autre de ces journaux.

Combien de requêtes ont été traitées au total depuis le début du fichier journal ?

 # grep -c BEGIN info.log 10

L'un d'entre eux a-t-il échoué (le script s'est-il arrêté sans atteindre la fin) ?

 # grep -c END info.log 10

Nous voyons que le nombre d'enregistrements BEGIN et END correspondent, cela nous indique donc que tous les appels ont réussi. (Si le script PHP ne s'était pas terminé avec succès, il n'aurait pas atteint l'exécution du script src/log-end.php .)

Quel était le pourcentage de requêtes à la racine du site ?

 # `grep -cE "\s/app_dev.php/$" info.log` 2

Cela nous indique qu'il y avait 2 chargements de page de la racine du site. Comme nous avons appris précédemment que (a) il y a 2 requêtes à l'application par chargement de page et (b) il y a eu un total de 10 requêtes HTTP, le pourcentage de requêtes à la racine du site était de 40 % (c'est-à-dire 2x2/10).

Quelle classe de contrôleur est responsable du traitement des requêtes à la racine du site ?

 # grep -E "\s/$|\s/app_dev.php/$" info.log | head -n1 Mar 3 12:04:20 log-sandbox 54f58724b1ccc: URI /app_dev.php/ # grep 54f58724b1ccc info.log | grep CONTROLLER Mar 3 12:04:23 log-sandbox 54f58724b1ccc: CONTROLLER Acme\DemoBundle\Controller\WelcomeController

Ici, nous avons utilisé l'ID unique d'une demande pour vérifier tous les messages de journal liés à cette demande unique. Nous avons ainsi pu déterminer que la classe de contrôleur responsable du traitement des requêtes à la racine du site est Acme\DemoBundle\Controller\WelcomeController .

Quels clients avec des adresses IP de sous-réseau 192.168.0.0/16 ont accédé au site ?

 # grep CLIENT info.log | cut -d":" -f4 | cut -f2 | sort | uniq 192.168.56.1

Comme prévu dans ce cas de test simple, seul mon ordinateur hôte a accédé au site. Il s'agit bien sûr d'un exemple très simpliste, mais la capacité qu'il démontre (de pouvoir analyser les sources du trafic vers votre site) est évidemment assez puissante et importante.

Quelle part du trafic vers mon site provient de FireFox ?

Ayant 1b101cd comme hachage de mon User-Agent Firefox, je peux répondre à cette question comme suit :

 # grep -c 1b101cd info.log 8 # grep -c CLIENT info.log 10

Réponse : 80 % (soit 8/10)

Quel est le pourcentage de demandes qui ont donné lieu à une réponse lente ?

Pour les besoins de cet exemple, nous définirons « lent » comme prenant plus de 5 secondes pour fournir une réponse. Par conséquent:

 # grep "DISPATCH TIME" info.log | grep -cE "\s[0-9]{2,}\.|\s[5-9]\." 2

Réponse : 20 % (soit 2/10)

Quelqu'un a-t-il déjà fourni des paramètres GET ?

 # grep URI info.log | grep \?

Non, le standard Symfony n'utilise que des slugs d'URL, donc cela nous indique également ici que personne n'a tenté de pirater le site.

Ce ne sont là que quelques exemples relativement rudimentaires de la manière dont les fichiers journaux peuvent être exploités de manière créative pour fournir des informations d'utilisation précieuses et même des analyses de base.

Autres choses à garder à l'esprit

Garder les choses en sécurité

Un autre avertissement concerne la sécurité. Vous pourriez penser que la journalisation des demandes est une bonne idée, dans la plupart des cas, c'est effectivement le cas. Cependant, il est important d'être extrêmement prudent lors de la suppression de toute information utilisateur potentiellement sensible avant de la stocker dans le journal.

Lutte contre le ballonnement du fichier journal

Étant donné que les fichiers journaux sont des fichiers texte auxquels vous ajoutez toujours des informations, ils ne cessent de croître. Comme il s'agit d'un problème bien connu, il existe des approches assez standard pour contrôler la croissance des fichiers journaux.

Le plus simple est de faire tourner les bûches . La rotation des bûches signifie :

• Remplacement périodique du journal par un nouveau fichier vide pour une écriture ultérieure
• Stockage de l'ancien fichier pour l'historique
• Suppression des fichiers qui ont suffisamment "vieilli" pour libérer de l'espace disque
• S'assurer que l'application peut écrire dans les journaux sans interruption lorsque ces modifications de fichiers se produisent

La solution la plus courante pour cela est logrotate , qui est livré préinstallé avec la plupart des distributions *nix. Voyons un fichier de configuration simple pour faire tourner nos logs :

 /var/log/my/debug.log /var/log/my/info.log /var/log/my/warning.log /var/log/my/error.log { rotate 7 daily missingok notifempty delaycompress compress sharedscripts postrotate invoke-rc.d rsyslog rotate > /dev/null endscript }

Une autre approche, plus avancée, consiste à faire en sorte que rsyslogd écrive lui-même des messages dans des fichiers, créés dynamiquement en fonction de la date et de l'heure actuelles. Cela nécessiterait toujours une solution personnalisée pour la suppression des fichiers plus anciens, mais permet aux devops de gérer précisément les délais pour chaque fichier journal. Pour notre exemple :

 $template DynaLocal0Err, "/var/log/my/error-%$NOW%-%$HOUR%.log" $template DynaLocal0Info, "/var/log/my/info-%$NOW%-%$HOUR%.log" $template DynaLocal0Warning, "/var/log/my/warning-%$NOW%-%$HOUR%.log" $template DynaLocal0Debug, "/var/log/my/debug-%$NOW%-%$HOUR%.log" local1.err -?DynaLocal0Err local1.info -?DynaLocal0Info local1.warning -?DynaLocal0Warning local1.debug -?DynaLocal0Debug

De cette façon, rsyslog créera un fichier journal individuel chaque heure, et il ne sera pas nécessaire de les faire tourner et de redémarrer le démon. Voici comment supprimer les fichiers journaux de plus de 5 jours pour mettre en œuvre cette solution :

 find /var/log/my/ -mtime +5 -print0 | xargs -0 rm

Journaux distants

Au fur et à mesure que le projet se développe, l'analyse des informations des journaux devient de plus en plus gourmande en ressources. Cela ne signifie pas seulement créer une charge de serveur supplémentaire ; cela signifie également créer une charge de pointe sur le processeur et les lecteurs de disque au moment où vous analysez les journaux, ce qui peut dégrader le temps de réponse du serveur pour les utilisateurs (ou dans le pire des cas, peut même faire tomber le site).

Pour résoudre ce problème, envisagez de configurer un serveur de journalisation centralisé . Tout ce dont vous avez besoin pour cela est une autre boîte avec le port UDP 514 (par défaut) ouvert. Pour que rsyslogd écoute les connexions, ajoutez la ligne suivante à son fichier de configuration :

 $UDPServerRun 514

Ayant cela, la configuration du client est alors aussi simple que :

 *.* @HOSTNAME:514

(où HOSTNAME est le nom d'hôte de votre serveur de journalisation distant).

Conclusion

Bien que cet article ait démontré certaines des manières créatives par lesquelles les fichiers journaux peuvent offrir des informations bien plus précieuses que vous ne l'aviez imaginé auparavant, il est important de souligner que nous n'avons fait qu'effleurer la surface de ce qui est possible. L'étendue, la portée et le format de ce que vous pouvez enregistrer sont presque illimités. Cela signifie que - s'il y a des données d'utilisation ou d'analyse que vous souhaitez extraire de vos journaux - vous devez simplement les enregistrer d'une manière qui facilitera l'analyse et l'analyse ultérieures. De plus, cette analyse peut souvent être effectuée avec des outils de ligne de commande Linux standard tels que grep , sed ou awk .

En effet, les fichiers journaux PHP sont un outil des plus puissants qui peut être d'un avantage considérable.

Ressources

Code sur GitHub : https://github.com/isanosyan/toptal-blog-logs-post-example

Annexe : lecture et manipulation des fichiers journaux dans le shell Unix

Voici une brève introduction à certains des outils de ligne de commande * nix les plus courants avec lesquels vous voudrez vous familiariser pour lire et manipuler vos fichiers journaux.

• cat est peut-être le plus simple. Il imprime l'intégralité du fichier dans le flux de sortie. Par exemple, la commande suivante imprimera logfile1 sur la console :

   cat logfile1

• > caractère permet à l'utilisateur de rediriger la sortie, par exemple vers un autre fichier. Ouvre le flux cible en mode écriture (ce qui signifie effacer le contenu de la cible). Voici comment nous remplaçons le contenu de tmpfile par le contenu de logfile1 :

   cat logfile1 > tmpfile

• >> redirige la sortie et ouvre le flux cible en mode ajout. Le contenu actuel du fichier cible sera conservé, de nouvelles lignes seront ajoutées en bas. Cela ajoutera le contenu de tmpfile logfile1

   cat logfile1 >> tmpfile

• grep filtre le fichier selon un motif et n'imprime que les lignes correspondantes. La commande ci-dessous n'imprimera que les lignes du logfile1 contenant le message Bingo :

   grep Bingo logfile1

• cut imprime le contenu d'une seule colonne (par numéro à partir de 1). Par défaut, recherche les caractères de tabulation comme délimiteurs entre les colonnes. Par exemple, si vous avez un fichier rempli d'horodatages au format YYYY-MM-DD HH:MM:SS , cela vous permettra d'imprimer uniquement les années :

   cut -d"-" -f1 logfile1

• head affiche uniquement les premières lignes d'un fichier

• tail affiche uniquement les dernières lignes d'un fichier

• sort trie les lignes dans la sortie

• uniq filtre les lignes en double

• wc compte les mots (ou les lignes lorsqu'il est utilisé avec le drapeau -l )

• | (c'est-à-dire, le symbole "tuyau") fournit la sortie d'une commande comme entrée à la suivante. Pipe est très pratique pour combiner des commandes. Par exemple, voici comment nous pouvons trouver les mois de 2014 qui se produisent dans un ensemble d'horodatages :

   grep -E "^2014" logfile1 | cut -d"-" -f2 | sort | uniq

Ici, nous faisons d'abord correspondre les lignes à l'expression régulière "commence par 2014", puis coupons les mois. Enfin, nous utilisons la combinaison de sort et uniq pour imprimer les occurrences une seule fois.