Archives pour l'étiquette closermag.fr

Le début: web access log logstash redis elasticsearch kibana

Gérer et monitorer les web access log avec logstash redis elasticsearch et kibana.

 

Voila une belle série de buzz word non ? Trêve de plaisanterie ! Je vais dans une série de note expliquer la création d’une pile applicative ELK (logstash elasticsearch kibana) que j’ai monté pour surveiller et navigué dans le flux des access log sur site www.closermag.fr

Acte 1 scène 1: Le défi des web access log

A l’origine sont les access log de plusieurs serveurs apaches ainsi que de plusieurs serveur varnish. Plusieurs défis sont à relever  :

  1. Généré des access log complet dans un format facilitant leur utilisation par la chaîne applicative souhaité
  2. La plupart des serveurs étant des machines virtuelles il est nécessaire de ne pas écrire sur disque. Le disque est le sous système le plus lent d’un serveur. Dans le cas d’une machine virtuelle, quelques soit l’approche ou la technologie, c’est encore pire.
  3. Le routage des flux de log apache comme varnish et leur concaténation dans un ensemble unique.

Acte 1 scène 2 : Les apaches

Pour les serveurs apaches la gestion de log et de leur format est un chose parfaitement documenté, je ne vais pas revenir dessus. Les access log devant être finalement enregistré dans elasticsearch dont la structure de stockage et sa hiérarchie étant basé sur le format JSON pour quoi ne pas les générer directement dans ce format et les router tel quel ?

Voici dont le format de log apache créé sur cette base et utilisé. Plusieurs itération et correction ont été intégré.

LogFormat "{ \
 \"@timestamp\": \"%{%Y-%m-%dT%H:%M:%S%z}t\", \
 \"@version\": \"1\", \
 \"vips\":\"%v\", \
 \"tags\":[\"apache\"], \
 \"message\": \"%h %l %u %t \\\"%r\\\" %>s %b\", \
 \"clientip\": \"%{X-Forwarded-For}i\", \
 \"duration\": %D, \
 \"status\": %>s, \
 \"request\": \"%U%q\", \
 \"urlpath\": \"%U\", \
 \"urlquery\": \"%q\", \
 \"bytes\": %B, \
 \"method\": \"%m\", \
 \"referer\": \"%{Referer}i\", \
 \"useragent\": \"%{User-agent}i\" \
 }" log_apache_json

Notez que :

  1. Le champs tags indiquant le type de la source
  2. Le champs clientip prend les ip d’origine de la requête et non ceux des lodbalancers ou reverse proxy en amont
  3. Que la duré de réponse est fourni via le champs duration
  4. Que le volume de donnée de la réponse est fourni par le champ bytes

Nous générons donc les access log directement dans un format facilitant leur utilisation par la chaîne d’application souhaité.

Acte 1 scène 3 : Le routage

Pour ne pas toucher aux disques le mieux est encore de transmettre directement les logs au démon syslog. Avec nginx c’est facile avec apache un peu moins.

Il est possible de transmettre les log apache à syslog avec l’utilitaire logger. Seulement logger à quelque limitation et comme une trame de log au format JSON est longue et dépasse parfois 1024 bits … logger la coupe en deux et envois deux trames syslog pour une trame access log. Il faut donc trouver autre chose.

Perl

Dans l’échange sur serverfault concernant les limitations de logger la solution est donné : Sys::Syslog. Il suffit de créé soit même un nouvel utilitaire capable de prendre en charge un trame dépassant les 1024 bits.

#!/usr/bin/perl
use Sys::Syslog qw (:DEFAULT setlogsock);
 
setlogsock('unix');
 
$ident = $ARGV[0];
@facilityandpriority = split(/\./, $ARGV[1]);
$facility = @facilityandpriority[0];
$priority = @facilityandpriority[1];
 
# open our log socket
openlog($ident, '', $facility);
 
# log all our input
while () {
 syslog($priority, $_);
}
 
# close the log socket
closelog;

Vhost et rsyslog

Nous avons le format de log et l’utilitaire de couplage avec syslog. Il reste à coller les bout ensemble.

Dans le vhost ont appel le format de log créé et on l’envois vers l’utilitaire. On fait le choix d’une catégorie et d’un priorité syslog, ici local0 et notice

CustomLog "||/usr/local/bin/to_rsyslog.pl closermag.fr local0.notice" log_apache_json

Dans la configuration rsyslog on précise que tout ce qui porte l’étiquette local0.notice est à envoyé à un serveur logmaster.

local0.notice @logmaster:514
& stop

Je précise que après l’envois au serveur logmaster le message syslog ne doit pas poursuivre et traverser les autres règles de traitement avec l’instruction & stop . Attention cette syntaxe est pour la version 8 de rsyslog que j’utilise. Comme la trame ne passe pas au travers des autres règles elle n’est pas enregistré dans un fichier, localement, sur disque.

Closermag, Nabilla et cache http

Le vendredi 7 novembre 2014 du fait de l’actualité people autour de la starlette Nabilla la plateforme hébergent le site Closermag.fr que j’administre enregistre +63% de requête supplémentaire. Je parle bien de requête http et non pas de visiteur unique qui est une donnée commercial qui ne représente en rien l’effort de production. Quand au page vue … elles sont constituées de plusieurs requête http d’un nombre variable, donc je n’utilise pas non plus cette mesure.

Il en ressort que le cache http est correctement configuré couplé avec l’utilisation de varnish  est une solution puissante pour absorber les pics d’audiences

Le challenge est la gestion des images. La photo à une part importante dans la mise en page et la ligne éditorial de closermag.fr . En conséquence les images sont nombreuses et de taille importantes. Différent choix ont été fait :

  • Isoler leur distribution dans un silo dédié basé sur varnish en frontend et nginx en backend. Le varnish bien que disposant d’un cache mémoire important de 8Go ne peux contenir l’intégralité des images, en conséquence avec nginx nous assurons son alimentation de façon performante.
  •  Les images de design du site on une durée de validité pour mise en cache d’une journée et celle d’illustration d’une année. Nginx ajoute des entêtes d’instruction du cache http.
  • Nous avons en outre fait le choix d’utiliser de multiple sous domaine afin de paralléliser les appels au maximum et de contourner les limites de certains navigateurs
  • Les images sont traitées afin d’en limiter le poids par la suppression des données Exif . Dans le processus d’alimentation en photos de Closermag l’utilisation de nombreux logiciel avait tendance à hypertrophier le volume de ces données.

Le 7 novembre 2014 un unique serveur varnish a assuré :

  • Un taux de réponse de 95% avec son cache, donc seul 5% des requêtes on du être demandé au backend ngnix.
  • Le pic de bande passante  de 149,91 Mb/s.
  • La réponse à une moyenne de 2660 req/s