Publié par
Il y a 9 années · 3 minutes · Java / JEE, Performance

Exception synchronisée

Symptômes

Lors d’un test de performance sur une application J2EE, je note que celle-ci a des soucis de montée en charge. Généralement une ou deux thread dumps peuvent mettre en évidence les points de contentions. Dans mon cas, rien de probant. Je repense alors à l’article publié sur notre blog Chroniques de la performance : À propos de contentions…. Je récupère les sources de l’agent et l’installe sur le serveur d’application, Weblogic 8.1 – JVM 1.4.2. Lancement du tir….

Dès le début de phase plateau, l’agent affiche régulièrement une partie du code que je n’aurais pas soupçonné: la bibliothèque iBatis qui gère l’accès aux données.

[JTPROF] Contention report [id=-1250505672,thread=ExecuteThread: '14' for queue: 'weblogic.kernel.Default',blocked=210ms]
[JTPROF] Stack trace:
[JTPROF]         com.ibatis.sqlmap.engine.accessplan.EnhancedPropertyAccessPlan. (EnhancedPropertyAccessPlan.java:29)
[JTPROF]         com.ibatis.sqlmap.engine.accessplan.AccessPlanFactory.getAccessPlan (AccessPlanFactory.java:62)
[JTPROF]         com.ibatis.sqlmap.engine.exchange.JavaBeanDataExchange.initialize (JavaBeanDataExchange.java:63)
[JTPROF]         com.ibatis.sqlmap.engine.mapping.parameter.BasicParameterMap.setParameterMappingList (BasicParameterMap.java:93)
[JTPROF]         com.ibatis.sqlmap.engine.builder.xml.SqlStatementParser.applyInlineParameterMap (SqlStatementParser.java:431)
[JTPROF]         com.ibatis.sqlmap.engine.builder.xml.SqlStatementParser.processSqlStatement (SqlStatementParser.java:215)
[JTPROF]         com.ibatis.sqlmap.engine.builder.xml.SqlStatementParser.parseGeneralStatement (SqlStatementParser.java:120)

Les temps de blocage affichés vont de 20ms à 500ms !

Analyse

A la lecture de cette pile d’appel, je me dis « encore un bloc synchronisé mal placé dans iBatis« . L’avantage avec l’open source, comme son nom l’indique, est que l’on a accès aux sources. J’ai donc ouvert la classe EnhancedPropertyAccessPlan qui, à ma grande déception, infirma ma 1ère intuition :

27  EnhancedPropertyAccessPlan(Class clazz, String[] propertyNames) {
28    super(clazz, propertyNames);
29    bulkBean = BulkBean.create(clazz, getGetterNames(propertyNames), getSetterNames(propertyNames), getTypes(propertyNames));
30  }

La ligne #29 indique l’appel à une méthode statique de la classe « BulkBean » qui appartient à la bibliothèque cgLib, bien connue pour accélérer efficacement la création de beans Proxy . Idem: cette méthode n’est pas ‘synchronized’. Alors pourquoi l’agent m’indique cette méthode ?
Les grands moyens : injection de traces manuelles dans le code d’iBatis afin de comprendre ce qu’il se trame. Après de nombreux allers-retours de type ‘essais-erreurs’, je finis par trouver l’origine du problème : chaque appel à la méthode BulkBean.create() engendre une levée d’exception NoClassDefFoundError.
En effet, le packaging de l’ear est incomplet : cglib.jar est bien présente mais il manque l’une de ses dépendances : asm. Or le code de la méthode BulkBean.create() s’appuie essentiellement sur l’API d’asm.
Cependant le packaging n’est pas le seul coupable, iBatis est également fautive ! La méthode AccessPlanFactory.getAccessPlan est extrêmement défensive : l’appel à EnhancedPropertyAccessPlan est gardé par un bloc try…catch(Throwable). L’ajout d’un message de log de type « Erreur » aurait été le bienvenue, au moins la première fois.

60:       if (bytecodeEnhancementEnabled) {
61:        try {
62:          plan = new EnhancedPropertyAccessPlan(clazz, propertyNames);
63:        } catch (Throwable t) {
64:          try {
65:            plan = new PropertyAccessPlan(clazz, propertyNames);
66:         } catch (Throwable t2) {
67:            plan = new ComplexAccessPlan(clazz, propertyNames);
68:          }
69:        }

Explications

La levée d’une exception dans une méthode oblige la JVM à rendre l’appel synchronisé afin de garantir un traitement par le catch cohérent. Il ne faudrait pas que les données (attributs, paramètres, variables) aient été modifiées par un autre thread entre la levée de l’exception et son éventuel traitement.

Pour se convaincre de ce phénomène, il suffit d’écrire une simple classe de test : 10 threads, chaque thread appelle une méthode qui suivant un paramètre lève une Exception, une Error ou ne fait rien, et ceci 1 000 000 de fois. Le résultat :

  • lorsque la méthode ne lève aucune Exception ou Erreur : Temps de réponse : 89 ms
  • lorsque la méthode lève une exception : Temps de réponse 5892 ms, 66 fois plus lent !

Règle: La levée d’exception doit rester un cas exceptionnel et ne dois en aucun cas devenir un design pattern, c’est même un anti-pattern.

public class AntiPattern {
	class NotEvenException extends Exception {
	}

	boolean isEven(int nb) {
		try {
			if (nb % 2 > 0)
				throw new NotEvenException();
			return true;
		} catch (NotEvenException e) {
			return false;
		}
	}
}

Note : Une fois le packaging complet, l’agent jtprof ne mentionne plus du tout cette zone de l’application.

7 réflexions au sujet de « Exception synchronisée »

  1. Publié par adiGuba, Il y a 9 années

    Salut,

    Plus précisément, le problème vient de la méthode fillInStackTrace() de Throwable.
    Cette méthode native et synchronisée est appelée par le constructeur de Throwable (et donc de toutes exceptions) pour générer le « stacktrace ».

    Cette information si utile est en effet assez couteuse à générer.

    Quelques infos supplémentaire sur ce billet : http://blog.developpez.com/adiguba?title=exception_et_performances

    a++

  2. Publié par Samuel, Il y a 9 années

    Merci pour ces infos et pour ce complément adiguba ;)

    Je pense avoir détecté une grosse erreur dans notre code grace à vous…

    Samuel

  3. Publié par Julien, Il y a 9 années

    Et quand on se rappelle que les EJB 2.x levaient des exceptions sur les finders lorsque ceci ne trouvaient pas de résultats, on a bien conscience à quel point c’était de la m$$%** :D

  4. Publié par Medo, Il y a 9 années

    Enfin un post technique francophone intéressant, c’est devenu tellement rare !

  5. Publié par Benoit Moussaud, Il y a 9 années

    Merci de vos remarques et de vos encouragements. C’est plaisant de savoir qu’il y a un public pour ce type d’articles.

  6. Publié par Thibaud, Il y a 9 années

    Entièrement d’accord avec Medo, surtout lorsque ce genre d’articles ouvre des perspectives d’optimisation de code, surtout quand on utilise les EJB (3 dans mon cas).

    D’ailleurs Julien, les query des EJB3 lancent aussi des exceptions de type NoResultException ou NonUniqueResultException.

    En tout cas, cet article nous donne plein de pistes à creuser pour améliorer notre code.

Laisser un commentaire

Votre adresse de messagerie ne sera pas publiée. Les champs obligatoires sont indiqués avec *