Rendre le code accessible en utilisant des ID de message uniques au monde

39

Un modèle commun pour localiser un bogue suit ce script:

  1. Observez l'étrangeté, par exemple, pas de sortie ou un programme suspendu.
  2. Recherchez le message pertinent dans le journal ou la sortie du programme, par exemple, "Impossible de trouver Foo". (Ce qui suit n'est pertinent que s'il s'agit du chemin emprunté pour localiser le bogue. Si une trace de pile ou d'autres informations de débogage sont facilement disponibles, c'est une autre histoire.)
  3. Localisez le code où le message est imprimé.
  4. Déboguer le code entre le premier endroit où Foo entre (ou devrait entrer) l’image et où le message est imprimé.

Cette troisième étape est celle où le processus de débogage s'arrête souvent car il y a de nombreux endroits dans le code où "Impossible de trouver Foo" (ou une chaîne basée sur un modèle Could not find {name}) est imprimé. En fait, plusieurs fois une faute d’orthographe m’a aidé à trouver l’emplacement réel beaucoup plus rapidement que je n’aurais pu le faire autrement: le message était unique dans l’ensemble du système et souvent dans le monde entier, ce qui entraînait immédiatement l’apparition d’un moteur de recherche pertinent.

La conclusion évidente est que nous devrions utiliser des identifiants de message uniques dans le code, en les codant en tant que partie intégrante de la chaîne de message et en vérifiant éventuellement qu'il n'y ait qu'une seule occurrence de chaque identifiant dans la base de code. En termes de facilité de maintenance, quels sont les avantages et les inconvénients les plus importants de cette approche pour cette communauté, et comment l’appliqueriez-vous ou garantiriez-vous qu’elle ne devienne jamais nécessaire (en supposant que le logiciel contiendra toujours des bogues)?

l0b0
la source
54
Utilisez plutôt vos traces de pile. La trace de la pile ne vous indiquera pas seulement précisément où l’erreur est survenue, mais également chaque fonction qui a appelé chaque fonction qui l’a appelée. Consignez toute la trace lorsqu'une exception se produit, si nécessaire. Si vous travaillez dans une langue qui n'a pas d'exceptions, comme C, c'est une autre histoire.
Robert Harvey
6
@ l0b0 un petit conseil sur la formulation. "Que pense cette communauté ... du pour et du contre" sont des expressions qui peuvent être considérées comme trop générales. Ceci est un site qui permet de "bonnes questions" subjectives, et en échange de permettre ce type de questions, vous, en tant que PO, serez censés faire le travail de "guider" les commentaires et les réponses vers un consensus significatif.
Rwong
@ rwong Merci! Je pense que la question a déjà reçu une très bonne réponse, bien que cela aurait peut-être été mieux posé dans un forum. J'ai retiré ma réponse au commentaire de RobertHarvey après avoir lu la réponse clarifiée de JohnWu, au cas où c'est ce dont vous parlez. Si non, avez-vous des conseils de berger?
l0b0
1
Mes messages ressemblent à "Impossible de trouver Foo lors de l'appel de bar ()". Problème résolu. Hausser les épaules. L'inconvénient, c'est que les clients le voient mal, mais nous avons de toute façon tendance à leur cacher les messages d'erreur, ce qui le rend disponible uniquement pour les administrateurs système qui ne peuvent pas donner à des singes la possibilité de voir certains noms de fonctions. En cas d'échec, oui, un joli petit identifiant / code unique fera l'affaire.
Courses de légèreté avec Monica
1
Ceci est TRÈS utile lorsqu'un client vous appelle et que son ordinateur ne fonctionne pas en anglais! Beaucoup moins d'un problème ces jours-ci car nous avons maintenant des fichiers de courrier électronique et de journal .....
Ian

Réponses:

12

Globalement, cette stratégie est valable et valable. Voici quelques réflexions.

Cette stratégie est également appelée "télémétrie" dans le sens où, une fois combinées, ces informations permettent de "trianguler" la trace d'exécution et permettent à un dépanneur de comprendre ce que l'utilisateur / l'application tente d'accomplir et ce qui s'est réellement passé. .

Certaines données essentielles à collecter (que nous connaissons tous) sont:

  • Emplacement du code, c'est-à-dire la pile d'appels et la ligne de code approximative
    • Une "ligne de code approximative" n'est pas nécessaire si les fonctions sont raisonnablement décomposées en unités suffisamment petites.
  • Toute donnée pertinente au succès / échec de la fonction
  • Une "commande" de haut niveau qui peut définir ce que l'utilisateur humain / l'agent externe / l'utilisateur de l'API tente d'accomplir.
    • L'idée est qu'un logiciel accepte et traite les commandes provenant de quelque part.
    • Au cours de ce processus, des dizaines, des centaines, des milliers, d'appels de fonction peuvent avoir eu lieu.
    • Nous aimerions que toute télémétrie générée tout au long de ce processus puisse être retracée jusqu'à la commande de niveau supérieur qui déclenche ce processus.
    • Pour les systèmes Web, la requête HTTP d'origine et ses données seraient un exemple de telles "informations de requête de haut niveau".
    • Pour les systèmes à interface graphique, l'utilisateur qui clique sur quelque chose correspond à cette description.

Souvent, les approches de journalisation traditionnelles ne donnent pas les résultats escomptés en raison de l'impossibilité de retracer un message de journal de bas niveau dans la commande de niveau supérieur qui le déclenche. Une trace de pile ne capture que les noms des fonctions les plus récentes qui ont aidé à gérer la commande de niveau supérieur, pas les détails (données) parfois nécessaires pour caractériser cette commande.

Normalement, les logiciels n'étaient pas conçus pour implémenter ce type d'exigences de traçabilité. Cela rend plus difficile la corrélation du message de bas niveau avec la commande de haut niveau. Le problème est particulièrement grave dans les systèmes multi-threadés, où de nombreuses requêtes et réponses peuvent se chevaucher et où le traitement peut être déchargé sur un thread différent du thread d'origine.

Ainsi, pour tirer le meilleur parti de la télémétrie, il sera nécessaire de modifier l’architecture logicielle globale. La plupart des interfaces et des appels de fonction devront être modifiés pour accepter et propager un argument "traceur".

Même les fonctions utilitaires devront ajouter un argument "traqueur", de sorte que, en cas d'échec, le message de journal se permette d'être mis en corrélation avec une certaine commande de haut niveau.

Un autre échec rendant le traçage de télémétrie difficile est le manque de références d’objet (pointeurs ou références nuls). Lorsque certaines données cruciales sont manquantes, il peut être impossible de signaler quoi que ce soit d’utile pour l’échec.

En termes d'écriture des messages du journal:

  • Certains projets logiciels peuvent nécessiter une localisation (traduction dans une langue étrangère) même pour les messages de journal destinés uniquement aux administrateurs.
  • Certains projets logiciels peuvent nécessiter une séparation claire entre les données sensibles et les données non sensibles, même à des fins de journalisation, et les administrateurs ne risquent pas de voir accidentellement certaines données sensibles.
  • N'essayez pas de brouiller le message d'erreur. Cela saperait la confiance des clients. Les administrateurs des clients s'attendent à lire ces journaux et à en comprendre le sens. Ne leur faites pas croire qu'il existe un secret de propriété qui doit être caché aux administrateurs des clients.
  • Ne vous attendez pas à ce que les clients apportent un journal de télémétrie et grillent votre personnel de support technique. Ils s'attendent à savoir. Entraînez votre personnel de support technique à expliquer correctement le journal de télémétrie.
rwong
la source
1
En effet, AOP a principalement vanté sa capacité inhérente à résoudre ce problème - en ajoutant Tracer à chaque appel pertinent - avec une invasion minimale de la base de code.
Mgr
J'ajouterais également à la liste des "messages de journal d'écriture" qu'il est important de caractériser l'échec en termes de "pourquoi" et de "comment réparer" au lieu de simplement "ce qui" s'est produit.
évêque
58

Imaginez que vous ayez une fonction utilitaire triviale utilisée à des centaines d’endroits de votre code:

decimal Inverse(decimal input)
{
    return 1 / input;
}

Si nous devions faire ce que vous suggérez, nous pourrions écrire

decimal Inverse(decimal input)
{
    try 
    {
        return 1 / input;
    }
    catch(Exception ex)
    {
        log.Write("Error 27349262 occurred.");
    }
}

Une erreur qui pourrait se produire est si l'entrée était zéro; cela donnerait lieu à une exception par division.

Supposons donc que vous voyez 27349262 dans votre sortie ou dans vos journaux. Où cherchez-vous le code qui a passé la valeur zéro? Rappelez-vous que la fonction - avec son ID unique - est utilisée dans des centaines d'endroits. Ainsi, bien que vous sachiez que la division par zéro a eu lieu, vous ne savez pas à qui 0elle appartient.

Il me semble que si vous ne voulez pas enregistrer les ID de message, vous pouvez également enregistrer la trace de la pile.

Si la verbosité de la trace de la pile vous dérange, vous n'avez pas besoin de la vider sous forme de chaîne de la façon dont le moteur d'exécution vous la donne. Vous pouvez le personnaliser. Par exemple, si vous voulez une trace de pile abrégée allant uniquement aux nniveaux, vous pouvez écrire quelque chose comme ceci (si vous utilisez c #):

static class ExtensionMethods
{
    public static string LimitedStackTrace(this Exception input, int layers)
    {
        return string.Join
        (
            ">",
            new StackTrace(input)
                .GetFrames()
                .Take(layers)
                .Select
                (
                    f => f.GetMethod()
                )
                .Select
                (
                    m => string.Format
                    (
                        "{0}.{1}", 
                        m.DeclaringType, 
                        m.Name
                    )
                )
                .Reverse()
        );
    }
}

Et utilisez-le comme ceci:

public class Haystack
{
    public static void Needle()
    {
        throw new Exception("ZOMG WHERE DID I GO WRONG???!");
    }

    private static void Test()
    {
        Needle();
    }

    public static void Main()
    {
        try
        {
            Test();
        }
        catch(System.Exception e)
        {
            //Get 3 levels of stack trace
            Console.WriteLine
            (
                "Error '{0}' at {1}", 
                e.Message, 
                e.LimitedStackTrace(3)
            );  
        }
    }
}

Sortie:

Error 'ZOMG WHERE DID I GO WRONG???!' at Haystack.Main>Haystack.Test>Haystack.Needle

Peut-être plus facile que de conserver les identifiants de message et plus flexible.

Voler mon code de DotNetFiddle

John Wu
la source
32
Hmm, je suppose que je n'ai pas bien expliqué mon point. Je sais qu'ils sont uniques Robert-- par code . Ils ne sont pas uniques par chemin de code . Connaître l'emplacement est souvent inutile, par exemple si le vrai problème est qu'une entrée n'a pas été définie correctement. J'ai légèrement modifié ma langue pour le souligner.
John Wu
1
Bons points, tous les deux. Il existe un problème différent avec les traces de pile, qui peuvent ou non constituer un facteur de désagrégation selon la situation: leur taille peut les submerger, notamment si vous souhaitez inclure la trace entière de la pile plutôt qu'une version abrégée, comme dans certaines langues. faire par défaut. Une autre solution consisterait peut-être à écrire un journal de trace de pile séparément et à inclure des index numérotés dans ce journal dans la sortie de l'application.
l0b0
12
Si vous en recevez tellement que vous craignez d'inonder votre I / O, il y a quelque chose qui ne va vraiment pas. Ou êtes-vous juste radin? La performance réelle est probablement le dépilage de la pile.
John Wu
9
Édité avec une solution pour raccourcir les traces de pile, au cas où vous écrivez des journaux sur une disquette 3.5;)
John Wu
7
@JohnWu Et n'oubliez pas non plus "IOException 'Fichier non trouvé' à [...]" qui vous dit environ cinquante couches de la pile d'appels mais ne dit pas quel fichier sanglant exact n'a pas été trouvé.
Joker_vD
6

SAP NetWeaver le fait depuis des décennies.

Il s’est révélé être un outil précieux lors du dépannage d’erreurs dans le gigantesque code énoncé qui constitue le système SAP ERP typique.

Les messages d'erreur sont gérés dans un référentiel central où chaque message est identifié par sa classe et son numéro.

Lorsque vous souhaitez émettre un message d'erreur, indiquez uniquement les variables de classe, de nombre, de gravité et spécifiques au message. La représentation textuelle du message est créée à l'exécution. Vous voyez généralement la classe et le numéro du message dans n’importe quel contexte dans lequel les messages apparaissent. Cela a plusieurs effets intéressants:

  • Vous pouvez rechercher automatiquement dans la base de code ABAP toutes les lignes de code créant un message d'erreur spécifique.

  • Vous pouvez définir des points d'arrêt de débogueur dynamiques qui se déclenchent lorsqu'un message d'erreur spécifique est généré.

  • Vous pouvez rechercher des erreurs dans les articles de la base de connaissances SAP et obtenir des résultats de recherche plus pertinents que si vous recherchiez "Impossible de trouver Foo".

  • Les représentations textuelles des messages sont traduisibles. Donc, en encourageant l'utilisation de messages plutôt que de chaînes, vous bénéficiez également des fonctionnalités i18n.

Un exemple de popup d'erreur avec le numéro du message:

erreur1

Recherche de cette erreur dans le référentiel d'erreurs:

erreur2

Trouvez-le dans la base de code:

erreur3

Cependant, il y a des inconvénients. Comme vous pouvez le constater, ces lignes de code ne sont plus auto-documentées. Lorsque vous lisez le code source et voyez une MESSAGEdéclaration telle que celles de la capture d'écran ci-dessus, vous ne pouvez déduire du contexte que ce que cela signifie réellement. De plus, les utilisateurs implémentent parfois des gestionnaires d’erreurs personnalisés qui reçoivent la classe et le numéro du message au moment de l’exécution. Dans ce cas, l'erreur ne peut pas être trouvée automatiquement ou ne peut pas être trouvée à l'emplacement où l'erreur s'est réellement produite. La solution de rechange au premier problème consiste à prendre l'habitude de toujours ajouter un commentaire dans le code source indiquant au lecteur la signification du message. Pour résoudre le second problème, ajoutez du code mort pour vous assurer que la recherche automatique de messages fonctionne. Exemple:

" Do not use special characters
my_custom_error_handler->post_error( class = 'EU' number = '271').
IF 1 = 2.
   MESSAGE e271(eu).
ENDIF.    

Mais il y a des situations où cela n'est pas possible. Il existe par exemple certains outils de modélisation de processus métier basés sur l'interface utilisateur dans lesquels vous pouvez configurer les messages d'erreur pour qu'ils apparaissent lorsque les règles métier sont violées. L'implémentation de ces outils étant entièrement basée sur les données, ces erreurs ne figureront pas dans la liste où elles sont utilisées. Cela signifie qu’il faut s’appuyer trop sur la liste utilisée pour trouver la cause d’une erreur.

Philipp
la source
Les catalogues de messages font également partie de GNU / Linux - et d’UNIX en tant que norme POSIX - depuis un certain temps.
évêque
@bishop En général, je ne programme pas spécifiquement pour les systèmes POSIX, donc je ne le connais pas bien. Peut-être pourriez-vous poster une autre réponse qui explique les catalogues de messages POSIX et ce que le PO pourrait apprendre de leur mise en œuvre.
Philipp
3
Je faisais partie d'un projet qui a fait cela dans les années à venir. Un problème que nous avons rencontré est que, avec tout le reste, nous avons mis le message humain pour "impossible de se connecter à la base de données" dans la base de données.
JimmyJames
5

Le problème avec cette approche est qu’elle conduit à une journalisation de plus en plus détaillée. 99,9999% de ce que vous ne regarderez jamais.

Au lieu de cela, je recommande de capturer l'état au début de votre processus et le succès / échec du processus.

Cela vous permet de reproduire le bogue localement, en parcourant le code et en limitant votre journalisation à deux emplacements par processus. par exemple.

OrderPlaced {id:xyz; ...order data..}
OrderPlaced {id:xyz; ...Fail, ErrorMessage..}

Maintenant, je peux utiliser exactement le même état sur ma machine de développement pour reproduire l'erreur, en parcourant le code de mon débogueur et en écrivant un nouveau test unitaire pour confirmer le correctif.

De plus, je peux, si nécessaire, éviter davantage de journalisation en ne journalisant que les échecs ou en conservant l'état ailleurs (base de données? File d'attente de messages?)

Évidemment, nous devons faire très attention à la journalisation des données sensibles. Cela fonctionne donc particulièrement bien si votre solution utilise des files de messages ou le modèle de magasin d'événements. Comme le journal doit seulement dire "Message xyz a échoué"

Ewan
la source
Mettre des données sensibles dans une file d'attente continue de la consigner. Ceci est déconseillé, tout comme le stockage d’entrées sensibles dans la base de données sans cryptage.
jpmc26
Si votre système utilise des files d'attente ou une base de données, les données sont déjà présentes, de même que la sécurité. Trop journaliser n'est que mauvais car le journal a tendance à tomber en dehors de vos contrôles de sécurité.
Ewan le
Oui, mais c'est le but. C'est mal avisé car ces données y restent en permanence et généralement en clair. Pour les données sensibles, il est préférable de ne pas prendre le risque et de minimiser l'endroit où vous le stockez, puis d'être très conscient et très attentif de la manière dont vous le stockez.
JPMc26
Il est traditionnellement permanent car vous écrivez dans un fichier. Mais une file d’erreurs est transitoire.
Ewan le
Je dirais que cela dépend probablement de la mise en œuvre (et peut-être même des paramètres) de la file d'attente. Vous ne pouvez pas simplement le déposer dans une file d'attente et vous attendre à ce qu'il soit sûr. Et que se passe-t-il une fois la file d'attente consommée? Les journaux doivent toujours être quelque part pour que quelqu'un les voie. De plus, ce n'est pas un vecteur d'attaque supplémentaire que j'aimerais ouvrir, même temporairement. Si une attaque découvre que des données sensibles y sont stockées, même les entrées les plus récentes pourraient être utiles. Et puis, il y a le risque que quelqu'un ne sache pas et qu'il retourne un commutateur pour qu'il commence également à se connecter au disque. C'est juste une boîte de Pandore.
JPMc26
1

Je suggérerais que la journalisation n'est pas la solution, mais plutôt que cette circonstance est considérée comme exceptionnelle (elle verrouille votre programme) et qu'une exception devrait être levée. Dites que votre code était:

public Foo GetFoo() {

     //Expecting that this should never by null.
     var aFoo = ....;

     if (aFoo == null) Log("Could not find Foo.");

     return aFoo;
}

Il semble que votre code d'appel n'est pas configuré pour traiter le fait que Foo n'existe pas et que vous pourriez potentiellement l'être:

public Foo GetFooById(int id) {
     var aFoo = ....;

     if (aFoo == null) throw new ApplicationException("Could not find Foo for ID: " + id);

     return aFoo;
}

Et cela retournera une trace de pile avec l'exception qui peut être utilisée pour aider au débogage.

Alternativement, si nous nous attendons à ce que Foo puisse être NULL lorsqu’il est renvoyé et que c’est bien, nous devons réparer les sites d’appel:

void DoSomeFoo(Foo aFoo) {

    //Guard checks on your input - complete with stack trace!
    if (aFoo == null) throw new ArgumentNullException(nameof(aFoo));

    ... operations on Foo...
}

Le fait que votre logiciel se bloque ou agisse "étrangement" dans des circonstances inattendues me semble mal - si vous avez besoin d'un Foo et que vous ne pouvez pas le supporter sans être présent, il semble préférable de s'effondrer que d'essayer de suivre un chemin corrompre votre système.

Paddy
la source
0

Les bibliothèques de journalisation appropriées fournissent des mécanismes d'extension. Par conséquent, si vous souhaitez connaître la méthode d'où provient un message de journal, ils peuvent le faire immédiatement. Cela a un impact sur l'exécution car le processus nécessite de générer une trace de pile et de la parcourir jusqu'à ce que vous soyez sorti de la bibliothèque de journalisation.

Cela dit, cela dépend vraiment de ce que vous voulez que votre identifiant fasse pour vous:

  • Corréler les messages d'erreur fournis à l'utilisateur avec vos journaux?
  • Indiquez la notation sur le code en cours d'exécution lorsque le message a été généré?
  • Garder une trace du nom de la machine et de l'instance de service?
  • Garder une trace de l'identifiant du fil?

Toutes ces choses peuvent être faites directement avec un logiciel de journalisation approprié (c'est-à-dire pas Console.WriteLine()ou Debug.WriteLine()).

Personnellement, le plus important est la capacité de reconstruire les chemins d'exécution. C'est ce que des outils comme Zipkin sont conçus pour accomplir. Un ID permettant de suivre le comportement d'une action d'un utilisateur sur l'ensemble du système. En mettant vos journaux dans un moteur de recherche central, vous pouvez non seulement rechercher les actions les plus longues, mais également appeler les journaux qui s'appliquent à cette action (comme la pile ELK ).

Les identifiants opaques qui changent avec chaque message ne sont pas très utiles. Un identifiant cohérent utilisé pour suivre le comportement à travers une suite complète de microservices ... extrêmement utile.

Berin Loritsch
la source