Accumulation de thread Tomcat

**Jackysousou** · 12/10/2013, 10h06

Bonjour,

Depuis plusieurs mois, je me penche régulièrement sur un problème tomcat d’accumulation de thread qui bloque les traitements serveurs jusqu'à ce que le nombre maximum de thread soit finalement atteint que le tomcat soit coupé.

Contexte :

Il s'agit un projet professionnel où l'application est utilisée par une soixantaine d'opérateurs.

Comme tout client lourd, l'application se connecte à un serveur d'application (ici, tomcat) pour effectuer ses requêtes en base de données. Pour cela, il va soit créer un nouveau thread serveur, soit en utiliser un ouvert et disponible.

Le problème survient de manière totalement aléatoire. Il arrive qu'un des traitements se bloque pour une raison X et tous les traitements suivant (donc les nouveaux threads ou les ré-utilisé) ne mettent en mode "wait" et s'accumulent constamment.

Voici une capture d'écran du manager à cet instant :

La première piste, ou pour dire vrai, la seule, qu'on a eu était vis à vis de la base de données. Certaines requêtes pouvaient être longue. On a donc augmenté le nombre maximum de thread actifs, ce qui a été bénéfique pendant plusieurs mois (cf. plus bas, le appContext.xml)
Cette modification a eu pour effet de tuer le thread après une période de X seconde libérant alors les thread suivant, ce qui a empêché de faire tomber le tomcat, mais bloquant les opérateurs le temps de la durée de vie du thread bloquant...

Configuration

Au niveau tomcat, le serveur.xml (cf. pièce jointe)

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
8
9
10
 
 <Service name="Catalina">
 
    <Executor name="tomcatThreadPool" namePrefix="catalina-exec-" maxThreads="200" minSpareThreads="40"/>
 
    <Connector executor="tomcatThreadPool" port="8081" protocol="org.apache.coyote.http11.Http11NioProtocol" scheme="http"
               connectionTimeout="40000" maxHttpHeaderSize="8192" acceptorThreadCount="4" 
               redirectPort="8443" xpoweredBy="false" server="server" allowTrace="false" />
 
...

Au niveau webApp, appContext.xml (cf. pièce jointe)

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
8
9
10
11
12
13
 
  <bean id="dataSource" class="org.apache.commons.dbcp.BasicDataSource" destroy-method="close">
    <property name="driverClassName" value="oracle.jdbc.driver.OracleDriver" />
    <property name="url" value="jdbc:oracle:thin:@${host}:${port}:${database}" />
    <property name="username" value="${database.username}" />
    <property name="password" value="${database.password}" />
    <!--property name="testOnBorrow" value="true" />
    <property name="testWhileIdle" value="true" />
    <property name="validationQuery" value="select 1 from dual" /-->
    <property name="maxWait" value="10000" />
    <property name="maxIdle" value="70" />
    <property name="maxActive" value="-1" />
  </bean>

L'objectif

Au pire, limiter le durée de vie d'un thread tomcat. De façon nominale, les traitements serveurs ne dépassent jamais les 30 secondes. On a essayé d'utiliser de nombreux paramètres, en vain...

Si quelqu'un a la moindre idée, je suis preneur.

Merci

**lunatix** · 12/10/2013, 23h39

il faut déterminer quel est le probleme

quand ton application bloque, il faut faire un threaddump de ta jvm
jstack <pid> >> threaddumps.log
(google thread dump java, tu verras y'a plein de methodes : kill -3 etc...)

tu devrais facilement trouver quel est le truc qui bloque. (tu vas surement avoir plein de threads coincés sur la même methode)

Apres tu ne pourras pas (a ma connaissance) limiter la durée du thread au niveau tomcat : il faut travailler coté code de l'application.
Par exemple passer par un executorService qui va executer les appels qui bloquents (on peut facilement mettre un timeout sur un executorservice) et y coller un Semaphore pour empecher d'avoir trop de threads bloqués dans une partie de code
http://docs.oracle.com/javase/6/docs...orService.html
http://docs.oracle.com/javase/6/docs...Semaphore.html

**Jackysousou** · 13/10/2013, 09h27

Merci pour ta réponse.

J'ai déjà fait un threaddump, mais l'étude du retour n'a pas été concluant.
De tête, il y avait que des thread en état "waiting"...
J'en referai un demain si je reproduis, et je posterai.

J'essaierai d'intégrer l'executorService et le Semaphore pour tester.

**tchize_** · 13/10/2013, 15h27

Envoyé par Jackysousou

.
De tête, il y avait que des thread en état "waiting"...

Ben oui, étonnant hein. La question n'est pas trop de savoir qu'ils sont en waiting (ça on en a une bonne idée au départ), la question est "sur quoi?". Tu regarde la ligne de code concernée, tu saura sur quel sémaphore ils attendent, tu regarde dans ton paquet quel est le thread qui possède le sémaphore (typiquement c'est celui qui attends pas au même endroit que les autres), et tu détermine ensuite par analyse du code pourquoi il ne rend pas le sémaphore.

Les raisons peuvent être nombreuses: erreur de programmation sur un sémaphore, un thread qui boucle infini, datasource consommé mais jamais rendu, etc...

**Jackysousou** · 15/10/2013, 10h39

Bonjour,

Je n'ai pas pu reproduire le problème ces 2 derniers jours, mais j'ai récupéré le thread dump d'avril, les choses n'ayant pas beaucoup changé...

Après une nouvelle analyse avec l'outil TDA - Thread Dump Analyser, on en est arrivé au même point : un soucis avec les accès hibernate/DB.

Il y a peut être quelque chose qui nous a échappé, je vous lie les threads dump concernés au cas où.

J'attends de reproduire pour un nouveau dump.

Merci.

**ra77** · 15/10/2013, 11h12

Envoyé par Jackysousou

Bonjour,

Je n'ai pas pu reproduire le problème ces 2 derniers jours, mais j'ai récupéré le thread dump d'avril, les choses n'ayant pas beaucoup changé...

Après une nouvelle analyse avec l'outil TDA - Thread Dump Analyser, on en est arrivé au même point : un soucis avec les accès hibernate/DB.

Il y a peut être quelque chose qui nous a échappé, je vous lie les threads dump concernés au cas où.

J'attends de reproduire pour un nouveau dump.

Merci.

Non il semble bien avoir un problème avec les accès hibernate/DB.

L'étape d'après est de regarder ce qu'il se passe au niveau bdd (requête SQL longue ?) + regarder la valeur du timeout tomcat <-> base de données (peut être faut il en mettre un plus agressif) + regarder la taille du pool de connexion (trop grand ? trop petit ?)

**tchize_** · 15/10/2013, 11h37

Pour regarder ton dump vite fait, je vois plein de threads en attente sur

org.apache.commons.pool.impl.GenericObjectPool.borrowObject

Autrement dit, ton connectionpool est épuisé. Cela peux arriver de plusieurs manières.

1) tu as une "fuite" de connexion: par exemple un beginTransaction jamais suivi d'un rollback ou d'un commit, une session hibernate jamais clôturée, etc. Bref, un problème de design quelque part dans le code. C'est assez chiant à trouver. Une technique consiste à réduire ton tomcat de test à quelques threads (3 ou 4), a réduire ton connexion pool à 1, et à tenter toutes les opérations de ton application jusqu'à en trouver une qui coince. Comme ton connexion pool est limité à 1, l'opération coupable sera celle qui précède l'opération qui coince. Suivant ton application, les 1 est à remplacer par le nombre minimum de connexion requise pour une requete (voir point suivant)

2) tu as juste un connexion pool trop petit et tu te retrouve en situation de deadlock. Cas d'exemple: tu as 10 threads, un pool de 5 connections. 5 threads ont obtenus 1 connections, 5 threads attendent une connexion, et chacun des 5 thread ayant déjà une connexion demande une deuxième connexion. Comme personne ne libérera de connexion avant d'en avoir reçu une, c'est cuit. Pour rappel, la taille minimum que doit faire ton connexion pool pour éviter le deadlock est

((N-1)*T)+1,
N étant le nombre de connexion que devra, dans le pire des cas, utiliser une requête pour répondre à une demande,
T le nombre de requetes maximum que ton conteneur peux faire en parallèle

3) ton connexion pool est trop petit et tu as une requete qui tourne en boucle infinie

Le point 2 est facile à vérifier: regarde si la taille max de ton connexion pool colle avec les besoins

Le point 1 est fort probable et une erreur courante -> les conteneurs fournissent des système pour les détecter. Tomcat utilise un timeout:

https://tomcat.apache.org/tomcat-6.0...ion_pool_leaks

Je pense que jboss est plus malin et enregistre toutes les connexion ouvertes par une requete http et les clotures à la fin de la requêtes avec un log du style "vos programmeurs sont incompétents, faites leur corriger ça"

Je ne pense pas que tu sois dans le cas numéro 3.

**Jackysousou** · 15/10/2013, 14h15

Très bien, je vais jongler avec ces paramètres.

Merci pour le tuyau.

Je vous dirai ce qu'il en est en fin d’après-midi.

**Jackysousou** · 21/10/2013, 09h46

Bonjour,

Je viens de reproduire, je monte à 380 threads.
J'ai modifié les paramètres en question, mais apparemment, ce n'est toujours pas assez.
Par contre, la trace du thread Dump est complètement différente...

**tchize_** · 21/10/2013, 10h34

D'après la stacktrace, tout fonctionne est est occupé de tourner (pas de thread HTTP en attente). Il reste plein de threads http-8081 disponibles, donc tomcat devrait continuer à servir les utilisateurs. Mise à part le nombre de thread élevé, tu rencontre toujours un soucis de fonctionnement? C'est peut-être juste le serveur qui est simple chargé là.

Aussi, je note quand même beaucoup de catalina-exec qui sont dans cet état:

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
8
9
	at sun.security.pkcs11.wrapper.PKCS11.C_DestroyObject(Native Method)
	at sun.security.pkcs11.SessionKeyRef.dispose(P11Key.java:1081)
	at sun.security.pkcs11.SessionKeyRef.drainRefQueueBounded(P11Key.java:1057)
	at sun.security.pkcs11.SessionKeyRef.<init>(P11Key.java:1072)
	at sun.security.pkcs11.P11Key.<init>(P11Key.java:98)
	at sun.security.pkcs11.P11Key$P11SecretKey.<init>(P11Key.java:379)
	at sun.security.pkcs11.P11Key.secretKey(P11Key.java:271)
	at sun.security.pkcs11.P11TlsRsaPremasterSecretGenerator.engineGenerateKey(P11TlsRsaPremasterSecretGenerator.java:83)
	at javax.crypto.KeyGenerator.generateKey(DashoA13*..)

D'après la jvm c'est en runnable. Mais il est possible que le code natif derrière attente sur un verrou non java => presque impossible à déterminer. Est-ce que ta communication avec ldap passe par une configuration spéciale? On dirait qu'une librairie native pkcs11 (utilisée en général pour les smartcard ou les certificats ssl de certaines sociétés) fous le bordel, mais je n'en suis pas sur. Avez vosu ajouté des librairies natives au tomcat où à la jvm?

**lunatix** · 21/10/2013, 10h47

visiblement, tous tes threads sont en train de faire une requete dans le serveur LDAP

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

fr.magellium.kheper.cha.database.dao.persistence.impl.LdapPersonDaoImpl.loginExists(LdapPersonDaoImpl.java:51)

c'est etrange (sauf si c'est le coeur de ce que font les utilisateurs avec l'appli), sinon, c'est la qu'est ton probleme

**Jackysousou** · 22/10/2013, 13h43

On vérifie systématiquement lors des appels aux différents services que le "user" est bien dans la ldap et autorisé à faire appel à tel ou tel service.

Je pense faire une espèce de maps (hashmap ou autre) de façon à ne vérifier qu'une seule fois les droits de l'utilisateur puis de stocker l'information dans le cas où ils les auraient.
Ca devrait limiter le nombre de requêtes au ldap...

**lunatix** · 22/10/2013, 15h04

Envoyé par Jackysousou

Je pense faire une espèce de maps (hashmap ou autre) de façon à ne vérifier qu'une seule fois les droits de l'utilisateur puis de stocker l'information dans le cas où ils les auraient.
Ca devrait limiter le nombre de requêtes au ldap...

Attention : avant de partir sur une solution, il faut finir de qualifier je pense : je te conseille de logger les temps d'acces aux ldap dans un fichier, pour valider que c'est bien la le soucis

(sinon, le risque, c'est de coller des rustines un peu partout a l'aveugle et de finir avec plus de problemes qu'au debut (par exemple un oom a cause de tes hashmaps etc... ))

**tchize_** · 22/10/2013, 15h08

Pourquoi tu ne laisse pas le conteneur ou un outil comme spring security faire cette vérification?

Normalement, au moment où tu reçois la requête, tu es censé faire les opération suivant:

1) vérifier le mot de passe
2) récupérer les rôles associés à l'utilisateur
3) exécuter la requête.

Tu n'a pas a interroger le ldap à chaque fois que tu veux vérifier un rôle. Tu dois récupérer la liste des rôles de l'utilisateur en même temps que tu vérifie le mot de passe. J'ai l'impression que tu fais plus d'une requête LDAP par connexion à un de tes service, pour vérifier probablement chaque étape.

**Jackysousou** · 23/10/2013, 13h53

On utilise bien spring security, et on vérifie bien que l'opérateur existe, que son mot de passe est le bon, et que son rôle l'autorise bien à exécuter telle ou telle requête. Donc en tout, 3 appels ldap.
Et ce test est fait à chaque appel au service...

**tchize_** · 23/10/2013, 14h08

Ce qui est embêtant, c'est que sur un threaddump "au hasard", tu aie autant de méthode en attente au même endroit, et à chaque fois c'est lié à

*.cha.database.dao.persistence.impl.LdapPersonDaoImpl.loginExists(LdapPersonDaoImpl.java:51)

Il me semble à lire l'aval, que ça utilise un threadpool ldap de spring, mais sans être sûr. Ce threadpool ne serait-il pas trop petit? Ou au contraire, est-ce que le serveur ldap ne serait pas configuré pour un truc du genre ma 10 connexion venant d'un même serveur?

Il faudrait faire ceci:

1) vérifier que c'est pas du gros hasard (genre t'as fait le test, pile poil au moment où le ldap a rendu l'âme pour 2 minutes) en refaisant un threaddump
2) si ça se confirme, nous donner la configuration de ton ldaptemplate dans spring, comment il est injecté dans LdapPersonDaoImpl, le code de loginExists, etc
3) nous préciser si tu as du ajouter des librairies particulière dans ton conteneur pour supporter ton ldap. Genre un gestionnaire SSL particulier.

**Jackysousou** · 23/10/2013, 18h07

Je n'ai pas ajouté de librairies particulières.

Le problème ne s'est pas reproduit aujourd'hui. Je mets quand même en pièce jointe la configuration et les classes associées.

**tchize_** · 23/10/2013, 19h48

une bonne chose serait de faire un thread dump quand tout va bien (mais que le serveur bosse) histoire d'avoir un point de comparaison

**Jackysousou** · 24/10/2013, 10h01

Ça a sauté ce matin...
Voici son thread dump et celui lors d'une situation "nominale"

**tchize_** · 24/10/2013, 11h04

Je crois qu'on peux en conclure une merde au niveau de la configuration LDAP/SSL

Cette pattern se répète ad vitam nauseam.
Il faudrait

1) ta configuration du ldaptemplate (elle n'était pas présente dans les sources que tu as données, jsute la configuration des webservices)
2) que tu regarde, quand le problème se produit, l'état des connection réseau entre ton serveur web et ton ldap (la commande netstat est ton amie)
3) j'aimerais avoir une idée de quelle jvm / quel os font tourner çà. J'ai trouvé une vague référence à ce problème, il s'agissait d'un solaris.

Code x :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
"Thread-75066" daemon prio=3 tid=0x00000001037b7800 nid=0x134b6 in Object.wait() [0xfffffffed6cff000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0xfffffffeea2edd38> (a java.lang.Object)
	at java.lang.Object.wait(Object.java:485)
	at com.sun.jndi.ldap.Connection.pauseReader(Unknown Source)
	at com.sun.jndi.ldap.Connection.run(Unknown Source)
	- locked <0xfffffffeea2edd38> (a java.lang.Object)
	at java.lang.Thread.run(Unknown Source)

"catalina-exec-64" daemon prio=3 tid=0x0000000105e41800 nid=0x134b5 runnable [0xfffffffed80f9000]
   java.lang.Thread.State: RUNNABLE
	at sun.security.pkcs11.wrapper.PKCS11.C_DestroyObject(Native Method)
	at sun.security.pkcs11.SessionKeyRef.dispose(P11Key.java:1081)
	at sun.security.pkcs11.SessionKeyRef.drainRefQueueBounded(P11Key.java:1057)
	at sun.security.pkcs11.SessionKeyRef.<init>(P11Key.java:1072)
	at sun.security.pkcs11.P11Key.<init>(P11Key.java:98)
	at sun.security.pkcs11.P11Key$P11SecretKey.<init>(P11Key.java:379)
	at sun.security.pkcs11.P11Key.secretKey(P11Key.java:271)
	at sun.security.pkcs11.P11TlsRsaPremasterSecretGenerator.engineGenerateKey(P11TlsRsaPremasterSecretGenerator.java:83)
	at javax.crypto.KeyGenerator.generateKey(DashoA13*..)
	at com.sun.net.ssl.internal.ssl.RSAClientKeyExchange.<init>(Unknown Source)
	at com.sun.net.ssl.internal.ssl.ClientHandshaker.serverHelloDone(Unknown Source)
	at com.sun.net.ssl.internal.ssl.ClientHandshaker.processMessage(Unknown Source)
	at com.sun.net.ssl.internal.ssl.Handshaker.processLoop(Unknown Source)
	at com.sun.net.ssl.internal.ssl.Handshaker.process_record(Unknown Source)
	at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(Unknown Source)
	- locked <0xfffffffee94d3240> (a com.sun.net.ssl.internal.ssl.SSLSocketImpl)
	- locked <0xfffffffeea33fe60> (a java.lang.Object)
	at com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(Unknown Source)
	- locked <0xfffffffeea33fe30> (a java.lang.Object)
	at com.sun.net.ssl.internal.ssl.SSLSocketImpl.startHandshake(Unknown Source)
	at com.sun.net.ssl.internal.ssl.SSLSocketImpl.startHandshake(Unknown Source)
	at com.sun.jndi.ldap.ext.StartTlsResponseImpl.startHandshake(Unknown Source)
	at com.sun.jndi.ldap.ext.StartTlsResponseImpl.negotiate(Unknown Source)
	at com.sun.jndi.ldap.ext.StartTlsResponseImpl.negotiate(Unknown Source)
	at org.springframework.ldap.core.support.AbstractTlsDirContextAuthenticationStrategy.processContextAfterCreation(AbstractTlsDirContextAuthenticationStrategy.java:109)
	at org.springframework.ldap.core.support.AbstractContextSource.getContext(AbstractContextSource.java:109)
	at org.springframework.ldap.core.support.AbstractContextSource.getReadOnlyContext(AbstractContextSource.java:125)
	at org.springframework.ldap.core.LdapTemplate.search(LdapTemplate.java:287)
	at org.springframework.ldap.core.LdapTemplate.search(LdapTemplate.java:237)
	at org.springframework.ldap.core.LdapTemplate.search(LdapTemplate.java:588)
	at org.springframework.ldap.core.LdapTemplate.search(LdapTemplate.java:546)
	at org.springframework.ldap.core.LdapTemplate.search(LdapTemplate.java:401)
	at org.springframework.ldap.core.LdapTemplate.search(LdapTemplate.java:421)
	at org.springframework.ldap.core.LdapTemplate.search(LdapTemplate.java:441)
	at fr.magellium.kheper.cha.database.dao.persistence.impl.LdapPersonDaoImpl.loginExists(LdapPersonDaoImpl.java:51)
	at sun.reflect.GeneratedMethodAccessor108.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.lang.reflect.Method.invoke(Unknown Source)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
	at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:155)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
	at com.sun.proxy.$Proxy146.loginExists(Unknown Source)
	at fr.magellium.kheper.cha.service.impl.LdapBAImpl.loginExists(LdapBAImpl.java:34)
	at sun.reflect.GeneratedMethodAccessor107.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.lang.reflect.Method.invoke(Unknown Source)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
	at org.springframework.aop.framework.adapter.AfterReturningAdviceInterceptor.invoke(AfterReturningAdviceInterceptor.java:50)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java:50)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:110)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:89)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
	at com.sun.proxy.$Proxy188.loginExists(Unknown Source)
	at fr.magellium.kheper.cha.webapp.security.ChaServerPasswordCallback.handle(ChaServerPasswordCallback.java:49)

Accumulation de thread Tomcat

Tomcat et TomEE Java

Discussions similaires

Partager

Partager