Comment diviser et consigner les temps d'exécution des différentes parties de votre application?

StackOverflow https://stackoverflow.com/questions/1026009

  •  06-07-2019
  •  | 
  •  

Question

Nous avons créé une application Web qui accepte les messages SOAP, effectue certains traitements, appelle un autre service Web, masse la réponse et la renvoie à l'appelant d'origine.

Nous aimerions enregistrer, sur une seule ligne, les différents temps d'exécution pour ces différentes étapes. Nous utilisons log4j avec la pile JBossWS. En d'autres termes, nous aimerions que la sortie du journal ressemble à ceci: 

2009-06-10T16:19:31.487 3336/2449/861

où 3336ms est le temps total passé à répondre à la demande, 2449ms, le temps d'attente de la réponse du service Web et 861ms, le temps consacré au traitement en interne des données.

Ces différents calculs ont lieu à différents endroits dans notre code et nous ne pouvons pas simplement les chronométrer et faire un appel à l'enregistreur à la fin d'une méthode unique. L'un de nous a suggéré d'utiliser le MDC de log4j pour cela, en tant que jeu de variables globales du pauvre pour suivre les différentes exécutions.

Mes questions sont donc les suivantes:

  1. Est-ce un abus horrible de l'intention première du MDC?
  2. Si oui, comment procéderiez-vous autrement?
Était-ce utile?

La solution

Consultez le profileur SLF4J . Assez intéressant. Il a été développé pour répondre exactement au même besoin, à savoir mesurer et améliorer les performances des appels SOAP.

Autres conseils

Cela ressemble à un travail pour Perf4J .

Je ferais ce qui suit:

  1. créer une classe PerformanceTimer, qui expose:
    • recordWaitedForWebServerReponse (idOpération, heure);
    • recordMassagedData (operationId, time);
    • autres méthodes, si nécessaire
  2. injecter cette classe là où c'est nécessaire;
  3. demandez à PerformanceTimer de gérer une mappe simultanée de OperationId - > OperationTimingData;
  4. sur l'appel de méthode connu comme étant le dernier, appelez Log4j avec le résultat souhaité.

Bien que cela fonctionnerait certainement, je recule à la pensée aussi. Ma suggestion serait de créer une classe de minutage juste à cette fin, qui utilise ThreadLocal pour créer une variable par requête.

Lorsque la requête arrive, vous créez la variable (un long avec l'heure de début). Lorsque la variable existe déjà, vous la laissez seule. Lorsque le résultat est renvoyé au client, vous calculez la durée et vous enregistrez.

J'utiliserais Spring et une programmation orientée aspect pour le faire. La bonne chose est que j’écrivais la logique une fois et l’appliquais de manière déclarative partout où j’en avais besoin.

Une méthode simple consiste à utiliser System.currentTimeMillis () , qui renvoie le temps en millisecondes. La différence entre le millisec au début de la méthode et les millisecondes à la fin de la méthode donnera le nombre de millisecondes pris pour exécuter cette méthode particulière. J'espère que System.currentTimeMillis () vous aidera.

Nous ne l'utilisons que dans notre premier filtre de requête: 

logger.trace("Init");
long start = System.currentTimeMillis();

//do stuff here 

long stop = System.currentTimeMillis();
String time = Util.getTimeDifferenceInSec(start, stop);
logger.trace("Complete in " + time + " sec");
Licencié sous: CC-BY-SA avec attribution
Non affilié à StackOverflow
scroll top