Comment lister tous les appels à une fonction dépréciée ?

Par @jbnahan69
Code source colorié sur une écran noir

Après le premier épisode de mon aventure de développeur Rust pour réaliser des sauvegardes en ligne, j'avais envie de vous partager en cette saint Valentin un bout de code qui m'a bien aidé.

Dans un projet, utilisant Symfony 5.4 et un CMS, un contrôleur réalisant une tâche assez lourde, ne fonctionnait plus en environnement de développement.

La faute aux innombrables appels à des fonctions dépréciés. Ces appels sont réalisés par des dépendances présentes dans les vendors.

Le problème est que le lien "Show trace" ne montre que la première trace alors qu'il y en a forcément plusieurs. (Rien que pour la première dépréciation elle a été levée 54 647 fois. Rien que ça. Je ne fais pas à moitié.)

Comment résoudre cette problématique avec uniquement la première trace qui ne m'aide pas du tout. J'ai donc écrit un hack DANS Symfony pour obtenir la liste exhaustive des traces.

Ajouter un espion

Comme tous plante, je n'ai pas la chance d'avoir le profiler Symfony, c'est pas grave, les logs sont peut être disponible... Et ... Bah ... Oui, ils sont là mais pèsent plus de 1 Go. En extrayant la fin du log, je constate qu'une dépréciation revient très souvent. Le log indique le fichier PHP et la ligne où la dépréciation a été signalée.

J'ouvre le fichier avec mon IDE et commence par commenter la dépréciation. Et là, telle la colombe sortant du chapeau, ça ne plante plus.

Maintenant, voyons la source de tous ces appels. Pour ça j'ai écrit le petit bout de code suivant:

        $stack = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS);
        $stack = array_map(function(array $item) {
            $str = '';
            foreach ($item as $key => $value) {
                $str.= $key.'=>'.$value."\n";
            }
            return $str;
        }, $stack);
        $strCall = implode("\n", $stack);
        $md5=md5($strCall);
        if (in_array($strCall, $this->callList)) {
            $this->callListCount[$md5]++;
        } else {
            $this->callListCount[$md5]=1;
            $this->callList[$md5]=$strCall;
        }

Son fonctionnement est simple, il récupère la pile d'exécution (liste de toutes les fonctions appelées pour arriver à l'exécution de la méthode dans laquelle ce code se trouve) sans les arguments.

Je reçois un tableau de données mais ce n'est pas pratique à manipuler par la suite, donc je le transforme en une simple chaine de caractère en veillant à la lisibilité.

Je calcul le MD5 (oui, il est vieux et faillible mais là je veux du simple, rapide, efficace et le risque de collision, bah il est faible pour ce cas) pour m'en servir de clé de tableau.

Dans un tableau, je stocke la chaîne de caractère et dans l'autre, le nombre d'appels réalisé.

Ah oui, attention, pour ceux utilisant déjà PHP 8.2, il est nécessaire de déclarer les fonctions pour éviter d'ajouter un Warning à la liste (pour les versions antérieures de PHP, j'utilise les propriétés dynamique qui sont toujours publiques)

public array $callList=[];
public array $callListCount=[];

Ce code est placé en dehors de la fonction dépréciée. Voici à quoi ça ressemble sur la classe "AbstractToken" de Symfony

Maintenant, pour obtenir le résultat, j'ajoute la ligne suivante à la fin du contrôleur :

dump($tokenStorage->getToken()->callList,$tokenStorage->getToken()->callListCount);

Bien sûr, j'ai ajouté la dépendance \Symfony\Component\Security\Core\Authentication\Token\Storage\TokenStorageInterface $tokenStorage dans la signature de ma fonction contrôleur.

Exploiter les données de l'espion

Après avoir réalisé l'appel à l'URL problématique, j'ai eu deux variables supplémentaires dans le panneaux "Debug" du profiler de Symfony.

L'une contient toutes les traces uniques des différents appels à la fonction dépréciée. L'autre contient le nombre d'appels réalisés pour chaque trace.

Il ne reste plus qu'à trouver une clé dont le nombre est supérieur à 1 pour avoir une piste d'une boucle problématique !

Avec la clé récupérée dans le tableaux des compteurs, je peux chercher dans l'autre tableau la trace correspondante:

Il ne reste plus qu'à trouver le meilleur moyen d'éviter ces appels en boucle. Ici, c'est une extension du logger. Donc son utilisation est directement lié à la quantité de log généré.

J'ai fini par trouver des endroits dans mon code que je n'avais pas encore corrigés (trouver les messages de dépréciation qui touche son code dans un tas de 700 à 800 lignes c'est pas facile). Après correction, le nombre d'appels avait énormément descendu. Après quelques refactorisations, le nombre a encore réduit pour finir sous la barre des 100 appels.

Une solution plus propre ?

Je vous le concède, cette solution n'est pas propre. Je vais modifier les fichiers présents dans le dossier "vendor" et j'utilise pas la force de Symfony pour corriger le problème.

La situation était telle que PHP manquait de ressource pour générer le profiler. L'exécution s'arrêta au milieu et la meilleure solution a été de commenter la ligne de code commençant par trigger_error dans le code source.

Sans avoir expérimenté, je pense qu'il est possible d'améliorer la situation avec le gestionnaire d'erreur. Celui qui écrit les messages dans le log.

Et vous, avez-vous été dans cette situation ? Comment l'avez-vous fait ? Vous pouvez me contacter pas là

Author avatar
Jean-Baptiste Nahan

Consultant Expert Web, j'aide les entreprises ayant des difficultés avec leur projet Web (PHP, Symfony, Sylius).

@jbnahan69 | Macintoshplus | Linkedin | JB Dev Labs