Saturday, October 16, 2010

Eclipse TPTP : Accélérer le "profiling"


Avant propos :
  • Le contenu de ce billet valable à partir de Java 5
  • Pour pouvoir tester les exemples présentés dans ce billet vous devez avoir correctement installé l'"Agent Controller" du projet Eclipse TPTP comme cela est décrit ici.
  • Si les notions d'"Agent" et d'"Agent Controller" ne vous disent rien vous pouvez vous rendre ici.
Performances, données et outils
Une séance de "profiling" peut très vite se trouver ralentie. Ce phénomène a en règle générale deux origines :
  1. La quantité de données collectées par l'outil, à plus forte raison si il s'agit d'une session distante ("Agent" sur une machine, client sur une autre).
  2. Les performances de l'outil qui va analyser et restituer ces données, si l'interface graphique fournie par Eclipse TPTP est très fournie il n'en reste pas moins que si la quantité de données à digérer est trop importante votre système pourrait ne plus répondre.
Sérialiser les données de « profiling » sur disque

Il s'agit ici de faire du « profiling » en « différé » : au lieu de connecter un outil qui va analyser directement les données (comme le Workbench Eclipse) nous allons les stocker sur disque, dans un fichier, pour les analyser à posteriori.

Avantages de cette méthode :
  • Pouvoir évaluer immédiatement la quantité de données recueillie en suivant l'évolution de la taille du fichier. Si le fichier atteint trop vite plusieurs centaines de Mo il faudra, vraisemblablement, arrêter, configurer des filtres (comme cela est décrit après) et recommencer.
  • Savoir clairement où les données collectées sont stockées
  • Collecter les données sur un système distant et faire l'analyse à posteriori sur une autre machine
Filtrer/Sélectionner les données à collecter
Afin de limiter la quantité d'information recueillie par l'Agent il est toujours préférable de mettre en place un système de filtrage. Le filtre va être défini par une liste de règles, séparées par des retours à la ligne. Une règle est composée de 3 colonnes, chacune séparées par un espace :
  1. La première colonne permet de désigner la classe et/ou le package Java ciblé par la règle
  2. La deuxième colonne contient le nom de la méthode. Il n'est pas nécessaire de spécifier une signature, seul le nom de la méthode suffit.
  3. La troisième colonne indique la visibilité de l'information : INCLUDE pour inclure la donnée ou EXCLUDE pour ne pas la sauvegarder.
Quelques astuces :
  • Les règles sont appliquées de haut en bas : plus une règle est en tête du fichier, plus elle est prioritaire.
  • Le caractère * peut être utilisé pour représenter n'importe quelle classe ou méthode (voir l'exemple plus bas).
  • Une bonne pratique consiste à exclure ce qui n'a pas été explicitement inclus, et donc de terminer le fichier par la ligne :
* * EXCLUDE

Importer les données dans le Workbench Eclipse
  • Dans la perspective Eclipse "Profiling and Logging perspective", sélectionner le menu "File" puis "Import" et enfin dans "Profiling and Logging" sélectionner "Profiling File" :



  • Sélectionner le fichier qui contient les données collectées et dans la liste des "Show..." bien sélectionner celle qui correspond aux données collectées.
  • Faire ensuite un clique droit sur les données importées et choisir l'éditeur qui convient. Dans le cas de données sur le temps d’exécution des méthodes sélectionner "Open with", "Execution Statistics".
Mise en pratique et exemple
J'ai développé deux servlets qui vont être déployées sur un serveur Apache Tomcat. Ces servlets ne vont rien faire d'autre que de concaténer des chaînes de caractères identiques mais de 2 manières différentes :
  1. L'une en utilisant le signe +
  2. L'autre en utilisant un StringBuilder
L'objectif est de mettre en évidence les temps d’exécution bien meilleurs de la classe StringBuilder.
L'option java suivante est ajoutée au démarrage du serveur d'application web Apache Tomcat :
-agentlib:JPIBootLoader=JPIAgent:server=standalone,file=c:\dev\tptp\tomcat_CGProf.trcxml,filters=c:\dev\tptp\tomcat_filter.txt;CGProf:execdetails=true
  Le mot clé "standalone" signifie à l'agent qu'il ne doit pas attendre ou se mettre à l'écoute d'un éventuel client et que les données collectées seront stockées sur disque. Le paramètre "file=" permet de désigner ce fichier.
 Dans un premier temps nous allons nous contenter d'analyser tous les appels aux méthodes doGet des servlets sans se préoccuper d'un package donné, le fichier tomcat_filter.txt va donc contenir :
* doGet INCLUDE
* * EXCLUDE


Chacune des servlets est appelée 2 fois : cela se retrouve dans la colonne Calls.
Description des autres colonnes :
  • Cumulative Time : temps total passé dans la méthode
  • Base Time : temps passé dans la méthode moins le temps d'appel des méthodes non filtrées appelées au sein de cette méthode : ici comme on filtre toutes les méthodes autres que les doGet on a Cumulative Time = Base Time
  • Average Base Time : Base Time moyen sur l'ensemble des appels

Pour analyser tous les appels aux méthodes des classes contenu dans un package donné et mieux comprendre la différence entre le "Base Time" et le "Cumulative Time" nous allons modifier le filtre pour tracer toutes les classes et méthodes de mon projet de test (dont les méthodes appelées dans les doGet), le fichier tomcat_filter.txt va donc contenir :
com.morello.* * INCLUDE
* * EXCLUDE


Notez maintenant comment pour la servlet com.morello.servlet.SimpleStringConcat.doGet(...) le "Base Time" a diminué alors que le "Cumulative Time" reste élevé. Cela est du au fait que l'on analyse plus de méthodes et que le responsable des mauvaises performances de cette servlet est com.morello.util.SimpleStringConcatUtil.getSimpleStringConcat().

Vous pouvez aussi vous rendre compte que pour réaliser une même concaténation de chaînes de caractère le signe + est près de 1000 fois plus lent que le classe StringBuilder !

Un petit exercice pour finir serait d'ajouter une nouvelle servlet pour comparer les résultats obtenu avec un StringBuilder dont le buffer interne est pré-dimensionné ou avec la classe StringBuffer, une version "thread safe" du StringBuilder.

Friday, October 15, 2010

Eclipse TPTP on IBM AIX platform

It seems that the Eclipse TPTP project has stopped to provide Agent Controller and agent libraries for some Unix platforms like IBM AIX.

I have just tried to use the IBM Rational Agent Controller (available at http://www-01.ibm.com/support/docview.wss?rs=2042&uid=swg27013420) with Eclipse TPTP 4.7.1 as client. Surprisingly it seems to be perfectly compatible, i have successfully collected profiling data on an Eclipse Workbench under Windows from a IBM J9 32bits VM SR8 running on a 64bits IBM AIX PowerPC 6.

Some tips :

  • While i tried to profile with an Xmx value equals or greater than 2048m the JVM crashed  with the following error as soon as i attached the Eclipse Workbench to the Agent Controller:
Unhandled exception
Type=Illegal instruction vmState=0x00000000
J9Generic_Signal_Number=00000010 Signal_Number=00000004 Error_Value=00000000 Signal_Code=0000001e
…..
Target=2_40_20100401_055940 (AIX 5.3)
CPU=ppc (4 logical CPUs) (0x200000000 RAM)
----------- Stack Backtrace -----------
---------------------------------------
JVMDUMP006I Processing dump event "gpf", detail "" - please wait.
JVMDUMP032I JVM requested System dump using 'core.20101013.171437.2584664.0001.dmp' in response to an event
Note: "Enable full CORE dump" in smit is set to FALSE and as a result there will be limited threading information in core file.
JVMDUMP006I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError" - please wait.
JVMDUMP006I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError" - please wait.
JVMDUMP010I System dump written to core.20101013.171437.2584664.0001.dmp
JVMDUMP032I JVM requested Snap dump using 'Snap.20101013.171437.2584664.0004.trc' in response to an event
JVMDUMP010I Snap dump written to Snap.20101013.171437.2584664.0004.trc
JVMDUMP032I JVM requested Java dump using 'javacore.20101013.171437.2584664.0005.txt' in response to an event
JVMDUMP032I JVM requested Snap dump using 'Snap.20101013.171440.2584664.0003.trc' in response to an event
JVMDUMP010I Snap dump written to Snap.20101013.171440.2584664.0003.trc
JVMDUMP032I JVM requested Snap dump using Snap.20101013.171440.2584664.0002.trc' in response to an event
JVMDUMP010I Snap dump written to Snap.20101013.171440.2584664.0002.trc
UTE430: can't allocate buffer
UTE437: Unable to load formatStrings for j9mm
JVMDUMP032I JVM requested Heap dump using 'heapdump.20101013.171440.2584664.0006.phd' in response to an event
JVMDUMP010I Java dump written to javacore.20101013.171437.2584664.0005.txt
JVMDUMP013I Processed dump event "gpf", detail "".

  • Do not forget to properly setup the LIBPATH environment variable in order to reference the lib and plugins/org.eclipse.tptp.javaprofiler directories. Agents rely on it to find the *.so files.
  •  Do not forget to start the AgentController on the AIX (with the ACStart.sh script in the bin directory) and, if it is not already done, to configure it with the SetConfig.sh Before trying to profile i suggest you to test the Agent Controller from a remote client with the SampleClient :
SampleClient <AIXHostName> <AgentControllerPort>

(Default AgentControllerPort is 10006)

Monday, October 11, 2010

TPTP Architecture, l'Agent Controller and co

N.B. : Les informations présentées ici ne sont valables qu'à partir de la version 5.0 de Java

Suite à un premier billet sur le mise en place de l'Agent Controller du projet TPTP en voici un autre pour décrire un peu plus précisément son architecture. Au premier abord il n'est en effet pas évident de s'y retrouver entre les éléments mis en jeu.

Vue d'ensemble de l'architecture

L'architecture de TPTP est organisée autour de 3 éléments :
  • L'Agent : il s'agit d'un programme qui s’exécute dans le même processus que la JVM. Il est notifié des évènements internes au travers de la JVM Tool Interface (JVMTI). JVMTI est une interface qui permet de connaître l'état de la JVM et de contrôler de manière avancée l'exécution des applications Java qui y sont exécutées.
  • L'Agent Controller : Il s'agit d'un programme qui doit résider sur la même machine que la JVM. Il gère tout le processus de démarrage et de communication avec l'agent. Il fait office de médiateur entre les agents et les clients.
  • Le Client : Dans le cadre de TPTP il s'agit en général de l'IDE Eclipse. Il collecte les données au travers de l'Agent Controller, cependant il n'est pas nécessaire que les 2 résident sur la même machine.


Quelques règles :
  • Un Client peut se connecter à un ou plusieurs Agent Controllers
  • Un Agent Controller peut servir zéro ou plusieurs Clients
  • Un Agent peut servir zéro ou plusieurs Clients
  • Un Client, au travers de l'Agent Controller, peut interagir avec zéro ou plusieurs Agents
  • Un Agent Controller peut contrôler zéro ou plusieurs Agents mais un Agent ne peut être connecté qu'à un seul Agent Controller.
Invocation d'un Agent au sein de la JVM
  Généralités
Les agents sont chargés au démarrage de la JVM grace à l'option suivante :
 -agentlib:<agent-lib-name>=<options>
Ce qui suit -agentlib: est le nom de la bibliothèque à charger. La recherche de cette bibliothèque est dépendante du système d'exploitation que vous utilisez. Elle doit être dans un chemin cité dans la variable d'environnement PATH sous Windows ou LD_LIBRARY_PATH sous Unix.
Par exemple si l'option -agentlib:foo=opt1,opt2 est spécifiée alors la JVM tentera de charger la bibliothèque foo.dll à partir d'un répertoire se trouvant dans la variable d’environnement PATH sous Windows ou bien libfoo.so dans la variable LD_LIBRARY_PATH sous Linux ou Solaris.

  Charger l'agent de TPTP
Je reviendrai plus en détail sur l'agent mis à disposition par le projet TPTP mais voici à quoi va ressembler l'option qui va permettre son chargement : 

-agentlib:JPIBootLoader=JPIAgent[:[help]|[<option>=<value>,...]];<profiler>[:<option>=<value>,...]

        Exemple :
 -agentlib:JPIBootLoader=JPIAgent:server=standalone;CGProf
  • JPIBootLoader : C'est la bibliothèque qui va charger l'agent
  • JPIAgent : C'est l'agent pour les version 5 et 6 de Java.
  • profiler : Charge une bibliothèque spécialisée dans un type  de "profiling" donnée, CGProf permet par exemple de surveiller les temps d’exécution.
La fin de la ligne est composée d'options sur lesquels je reviendrai en détail plus tard....

Sunday, October 10, 2010

Eclipse TPTP : Installation de l'Agent Controller

C'est en général une fois l'application développée que les questions de performance surgissent : temps de traitement et de réponse en dessous des espérances ou encore consommation mémoire élevée avec un "garbage collector" qui peine à faire son travail sans trop pénaliser l'applicatif. La complexité des piles Java actuelles n'aidant pas forcément à y voir plus clair on peut se retrouver vite désarmé lorsqu'il s'agit d'expliquer une consommation inhabituelle des ressources ou des temps d'attente anormaux.

Ayant fait face à plusieurs reprises à ce genre de situations j'ai décidé d'écrire une série de billets sur la recherche  et la détection de ces "goulots" qui pénalisent les performances d'un application.

Avant de pouvoir profiter pleinement des possibilités offertes par TPTP ce billet a pour objectif de présenter comment installer de manière propre l'Agent Controller (appelé AC par la suite).
L'Agent Controller c'est un programme chargé de collecter et de redistribuer localement ou à des clients distants des informations sur l’exécution d'un programme Java, mais comme nous le verrons dans les autres billets c'est aussi un ensemble de bibliothèques qui vont nous permettre d'instrumenter en profondeur une machine virtuelle Java.

Note : Ce billet concerne pour le moment uniquement Windows car d'expérience je sais que c'est la plateforme la plus utilisée lors des développements, je la compléterai plus tard avec une version Linux.

Pourquoi installer proprement l'Agent Controller ?

Car c'est la manière la plus simple de tirer pleinement profit des outils de "profiling" du projet Eclipse TPTP :
  • Le profiling de l'application en direct et en local depuis l'IDE Eclipse
  • Le profiling de l'application à distance et en direct
  • Le profiling de l'application en local, ou à distance, et en "différé", extrêmement utile pour optimiser les informations collectées et ne pas saturer l'interface d'Eclipse.
  • L'utilisation du "ProbeKit" qui va permettre d'instrumenter la JVM afin de faire du débogage de manière très avancé dans presque n'importe quelle portion du code exécuté ou pour les plus curieux de faire du "reverse-enginnering"
Tous ces points seront décrits dans des prochains billets.

Etape 1 : Télécharger l'Agent Controller

La page d'accueil du projet TPTP est http://www.eclipse.org/tptp/
A l'heure où ce billet est écrit c'est la version 4.7.1 du projet TPTP qui est en téléchargement. Pour télécharger l'Agent Controller rendez vous sur la page http://www.eclipse.org/tptp/home/downloads/?ver=4.7.1#agentController et choisissez le runtime pour votre plateforme.

Etape 2 : Dézipper l'archive et configurer l'agent

Dézippez l'archive avec l'utilitaire de votre choix (comme 7zip). Évitez autant que possible les chemins avec des espaces ! Pour ma part j'ai copié l'archive zip dans le répertoire C:\dev\tptp\agntctrl :

Il faut maintenant configurer un minimum l'Agent Controller pour qu'il sache ce qu'il a le droit de faire. Pour cela lancer le programme SetConfig.bat qui doit se trouver à la racine du répertoire dans lequel vous avez extrait l'archive :


Vous devez répondre à trois questions :

  1. Donner le chemin complet vers le programme javaw.exe qui est dans le répertoire bin de votre JRE. (note : j'utilise ici une JVM 1.6)
  2. Depuis quelle machine peut-t-on se connecter à l'Agent Controller ? Je vous conseille de répondre ALL, c'est le plus simple pour pouvoir faire plus tard du profiling à distance, si vous démarrez et arrêtez l'Agent Controller manuellement cela ne doit pas poser de problème de sécurité.
  3. Activer la sécurité ? Encore une fois si vous démarrez l'agent à la main de manière occasionnelle il n'est pas nécessaire d'activer la sécurité.


Etape 3 : Configurer l'environnement de Windows
Il est maintenant impératif de placer certains répertoires dans la variable d’environnement PATH de Windows :
  • Pour faire les choses proprement on commence par définir la variable TPTP_AC_HOME en lui attribuant comme valeur le chemin dans lequel on a "dézippé" l'archive contenant l'Agent Controller, dans mon cas ce sera donc C:\dev\tptp\agntctrl :

  • Cherchez maintenant la variable Path, cliquer sur modifier et insérer au début du champ "Valeur de la variable :" la chaîne suivante :
%TPTP_AC_HOME%\plugins\org.eclipse.tptp.javaprofiler;%TPTP_AC_HOME%\bin;%TPTP_AC_HOME%\plugins\org.eclipse.hyades.probekit\lib;

Le point virgule à la fin est important ! Il permet de séparer les différents chemins et est donc indispensable.

Etape 4 : Tester la configuration

  1. Ouvrir 2 terminaux de commande Windows : Démarrer -> Exécuter... -> cmd -> Entrée
  2. Dans les 2 terminaux se positionner dans le répertoire %TPTP_AC_HOME%\bin
  3. Dans le premier taper la commande ACServer.exe
  4. Dans le deuxième taper SampleClient.exe

La commande lancée en bas permet de valider le bon fonctionnement de l'agent en local
Note importante pour ceux qui utilisent Windows Vista :
ACServer.exe nécessite des droits d'administrateurs. Pour cela, dans l'explorateur Windows, faire un clique droit sur ACServer et sélectionner  "Properties".  Dans l'onglet "Compatibility", sélectionner la boite à cocher nommée "Run As Administrator" et cliquer sur  Apply.

Vous pouvez aussi tester un Agent Controller sur une machine distante en lui passant en argument le nom ou l'adresse IP de l’hôte qui l'héberge suivi du numéro de port (par défaut celui ci est 10006)


Conclusion

Ce travail peut paraître fastidieux mais il va nous permettre dans les billets suivants de jouer pleinement et de manière optimisé avec TPTP.