Les logs servent à remplir les disques (souvent) et à déboguer (parfois), mais pas que. Logstash a démontré que l’on pouvait entasser des logs dans un moteur de recherche pour faciliter les analyses postmortem d’incidents. On peut aussi compter des trucs et des machins pour faire de jolis graphes, voir même, en lâchant des sous, avoir des alertes avec alerting. Elasticsearch propose aussi la notion de percolate avec ses recherches à l’envers. Les notions existent et sont même déjà implémentées (en Java).
Voici une présentation pédagogique, avec une implémentation toute légère en golang, pour chercher des motifs dans des flots de logs : Yangtze 长江.
Concept
L’idée de base est d’enregistrer des requêtes, et de leur soumettre des lignes de log. C’est la percolation d’Elasticsearch.
Pour ne pas tout bouffer la RAM et le CPU, les expressions régulières ne seront surtout pas utilisées de manière systématique.
Même si Grok permet d’écrire des regex concises et compréhensibles, même si RE2 limite le bazar des très classiques PCRE, les regexps restent un marteau qui scalent mal. C’est vrai, Piwik (enfin, Matomo) l’a prouvé avec son parser de user-agent.
Indexer une expression régulière oblige à la déplier, et c’est rapidement pénible à faire (du code ruby existe et fonctionne plutôt bien), pour un résultat peu concluant.
L’idée est de découper le motif en jetons (en tokens, en mots, quoi), et de les utiliser pour indexer les requêtes. En découpant les lignes de logs en jeton, on peut retrouver les requêtes correspondantes, et ne tester le motif que sur les lignes qui ont les jetons nécessaires.
Implémentation
Motifs
Plutôt que d’aller se coincer dans du vrai regex, je pars sur un sous-ensemble minimaliste :
.un jeton?zéro ou un jeton...plusieurs jetons
Tokenisation
La tokenization est tout aussi brutale, les jetons sont constitués de lettres, de chiffres, de _ et de -. Tout le reste, ponctuation, parenthèses, espaces… est considéré comme des séparateurs.
Je [mange] des carottes.
Va donner :
- Je
- mange
- des
- carottes
Les tokens qui sont indexés (ceux des requêtes, pas ceux des lignes) sont rangés dans un tableau, et un identifiant (un simple compteur) leur est attribué. Par convention, les identifiants commencent à 1, 0 est réservé pour gérer le rien, un token qui n’est pas indexé.
Avec la tokenisation et les identifiants, on peut transformer une ligne en une suite de nombres.
"a ... c" => [1, 0, 2] // un motif
"a a b c" => [1, 1, 0, 2] // une ligne
Bitset
Les bitsets sont de longues suites de booléens, leur rang correspond à leur valeur. Par convention, le 0 est toujours false. Avec un bitset, on ne peut savoir que si un jeton est présent ou non, on perd sa position et son nombre d’occurrences. Par contre, il est facile d’effectuer des opérations booléennes, des opérations sur des ensembles, ou compter le nombre de bits allumés (on parle alors de cardinalité).
"a ... c" => ◻︎◼︎◼︎
"c . a" => ◻︎◼︎◼︎
"a a" => ◻︎◼︎◻︎
"a a b c" => ◻︎◼︎◼︎
Une ligne avec une cardinalité nulle ne matchera jamais, première simplification.
Si le bitset d’une requête n’est pas inclus dans le bitstet de la ligne, on sait que ça ne matchera pas.
set("a ... c") ⊂ set("a a b c")
set("c . a") ⊂ set("a a b c")
Si ces deux premières conditions sont passées, on peut tester le motif (en travaillant sur les suites de nombres).
pattern("a ... c").match("a a b c") == True
pattern("c . a").match("a a b c") == False
Pour limiter le travail, les requêtes sont indexées par jetons. Pour l’instant, le jeton de la ligne utilisé pour tirer les requêtes potentielles est le premier. Pour bien faire, il faudrait trier les jetons par occurrence, et choisir le moins courant (et donc le plus discriminant).
Performance
Les performances de regexp de golang, basé sur RE2, sont très bonnes. Tokenizer une ligne, vérifier si le motif correspond est plus que de tester une expression régulière. Mais ça tombe bien, ce n’est pas le cas d’usage, on tokenize une fois, exclue puis test le motif plein de fois. Obtenir l’identifiant d’un jeton est super rapide, travailler avec les bitsets et vérifier les motifs sont aussi super rapide, bien plus qu’une regexp. Le cout de la tokenization (qui gère de manière orthodoxe l’UTF8) est très rapidement amorti quand il s’agit de tester une brouette de motifs.
Préparer une ligne est 4 fois plus long que de lancer une regexp, mais tester un motif est presque 10 fois plus rapide.
Bon, un benchmark est toujours un peu raide et rien ne remplace un vrai usage.
Usage
Avoir de jolis tests unitaires et des benchmarks, c’est bien, avoir du code utilisable, c’est mieux. Le premier usage sera de surveiller des flots de logs (tail, journald, fluentd…) pour soit lever des erreurs qualifiées (sentry, alertmanager, alerta), soit compter des trucs qui finiront dans du timeseries. Des actions à la fail2ban sont potentielement envisageable.