🐛 Les requêtes SQL au texte trop long génèrent des lignes de log trop longues pour être traitées

💣 Problème

Quand les statistiques de requêtes collectées périodiquement (événements db-query-stats) incluent une requête donc le texte SQL dépasse une certaine taille, la ligne de log JSON correspondante qui est générée par pix-db-stats se trouve "tronçonnée" en plusieurs lignes et à l'arrivée sur Datadog elle n'est pas traitée puisque ce n'est plus du JSON valide. Ces requêtes disparaissent donc complètement des statistiques — alors que leur taille même devrait les rendre candidates à un examen approfondi).

🔬 Analyse

La limite de taille documentée chez Datadog est de 1 Mo par ligne, et on est loin de cette taille pour les lignes qui posent problème. En revanche, en allant voir les logs à la source chez Scalingo (scalingo --region osc-secnum-fr1 -a pix-db-stats-production logs -n 100000|sort|awk '/\] [^{]/{print substr($0, 1, 100), length($0)}' pour lister les lignes ne commençant pas par { avec leur longueur), je constate que le découpage des lignes a déjà lieu chez Scalingo, à une longueur de 16384 (2^14) caractères. Bien que cette limitation ne semble pas documentée, il paraît très vraisemblable qu'elle soit appliquée par Scalingo et non dans l'application qui utilise simplement un console.log pour générer ces lignes :

pix-db-stats/lib/infrastructure/logger.js

Line 3 in 2c89696

console.log(JSON.stringify({ event, app, data }));

💡 Suggestion de solution

S'assurer que les lignes de log restent bien en-dessous des 16384 caractères. C'est probablement compliqué de trouver une solution générique qui pourrait s'appliquer au niveau du logger — on pourrait imaginer une variante de JSON.stringify qui prenne un paramètre de longueur maximale et qui garantisse la génération d'un JSON valide dans cette limite en appliquant par exemple un heuristique de troncature des chaînes les plus longues… c'est un programme de recherche intéressant mais peut-être excessif ici.

Pragmatiquement, appliquer une limite raisonnable à la chaîne de requête SQL capturée ici :

pix-db-stats/lib/application/task-statements.js

Line 9 in 2c89696

    
           queryStats.forEach((query) => logger.info({ event: 'db-query-stats', app: scalingoApp, data: query }))

devrait être suffisant. La partie tronquée pourrait être remplacée par …, ou éventuellement de manière plus subtile par un hash des données tronquées afin d'éviter de confondre plusieurs requêtes qui auraient un préfixe commun.

On a changé l'événement db-query-stat pour renvoyer seulement ce qui nous intéresse. Nous n'avons plus ces problèmes