Problème transaction JTA timeout

Bonjour,

Voilà, vous êtes mon dernier espoir, impossible de trouver une piste, j'ai cherché dans tous les sens...

Mon cas: nous avons une application Web qui, en fin de traitement, poste un message dans une queue JMS. Ce message est consommé par un mdb qui effectue une réplication de données vers une autre db. Le message contient donc un id, qui permet de lire de la db source, pour ensuite répliquer vers la db destination.

Comme il y a 2 db et un jmsfilestore, que j'utilise les transactions CMT, les sessions JMS sont des sessions XA et donc, les datasources des db aussi.

Tout fonctionne très bien en test, en acceptation MAIS, en production, on a des erreurs de timeout :( ça arrive environ 1x sur 10....). Normalement le traitement prend moins d'une seconde...

Pour info, nous utilisons Hibernate. Mais je ne vois pas en quoi ça peut changer la donne :-) Les requêtes ont été contrôlées et sont performantes. J'ai l'impression que c'est la charge qui cause ces problèmes... peut-être un deadlock,... (je ne m'y connais pas trop de ce côté...).

Ca plante toujours au même endroit... la requête générée apr Hibernate à cet endroit n'a rien d'exceptionnel... il attend sans doute quelque chose pour terminer mais je ne sais pas quoi et je ne sais pas ou regarder... (j'ai déjà épeluché les logs JTA, système, en existe-t-il d'autres?)

Bon... c'est pas évident mais si vous avez une idée, je suis preneur :)

Merci :-)

voici la stacktrace:

Code:

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
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
 
Fail message with id: ID:<475066.1229500219278.0>
Message content was: <file><type>subContractorParticipation</type><id>1822387</id><part>528503</part></file>
 
With exception:
org.hibernate.exception.GenericJDBCException: could not load an entity: [ak.kille.dk80.core.data.model.actor.Actor#41868]
		 at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:91)
		 at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:79)
		 at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
		 at org.hibernate.loader.Loader.loadEntity(Loader.java:1799)
		 at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:93)
		 at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:81)
		 at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:2730)
		 at org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:365)
		 at org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:346)
		 at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:123)
		 at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:82)
		 at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:891)
		 at org.hibernate.impl.SessionImpl.immediateLoad(SessionImpl.java:849)
		 at org.hibernate.proxy.AbstractLazyInitializer.initialize(AbstractLazyInitializer.java:62)
		 at org.hibernate.proxy.AbstractLazyInitializer.getImplementation(AbstractLazyInitializer.java:98)
		 at org.hibernate.proxy.CGLIBLazyInitializer.intercept(CGLIBLazyInitializer.java:158)
		 at ak.kille.dk80.core.data.model.actor.Actor$$EnhancerByCGLIB$$50efe36c_2.getDenom(<generated>)
		 at ak.kille.dk80.replicator.mdb.business.logic.impl.SubContractorParticipationReplicator.createSubContractorRelation(SubContractorParticipationReplicator.java:202)
		 at ak.kille.dk80.replicator.mdb.business.logic.impl.SubContractorParticipationReplicator.process(SubContractorParticipationReplicator.java:85)
		 at ak.kille.dk80.replicator.mdb.business.logic.impl.ReplicatorServiceImpl.replicateSubContractorParticipation(ReplicatorServiceImpl.java:96)
		 at ak.kille.dk80.replicator.mdb.MdbReader.replicate(MdbReader.java:131)
		 at ak.kille.dk80.replicator.mdb.MdbReader.onMessage(MdbReader.java:81)
		 at weblogic.ejb.container.internal.MDListener.execute(MDListener.java:466)
		 at weblogic.ejb.container.internal.MDListener.transactionalOnMessage(MDListener.java:371)
		 at weblogic.ejb.container.internal.MDListener.onMessage(MDListener.java:327)
		 at weblogic.jms.client.JMSSession.onMessage(JMSSession.java:4072)
		 at weblogic.jms.client.JMSSession.execute(JMSSession.java:3964)
		 at weblogic.jms.client.JMSSession$UseForRunnable.run(JMSSession.java:4490)
		 at weblogic.work.SelfTuningWorkManagerImpl$WorkAdapterImpl.run(SelfTuningWorkManagerImpl.java:464)
		 at weblogic.work.ExecuteThread.execute(ExecuteThread.java:200)
		 at weblogic.work.ExecuteThread.run(ExecuteThread.java:172)
Caused by: java.sql.SQLException: Unexpected exception while enlisting XAConnection java.sql.SQLException: Transaction rolled back: Transaction timed out after 31 seconds 
BEA1-13BEA4F92011079B969A
		 at weblogic.jdbc.jta.DataSource.enlist(DataSource.java:1419)
		 at weblogic.jdbc.jta.DataSource.refreshXAConnAndEnlist(DataSource.java:1331)
		 at weblogic.jdbc.wrapper.JTAConnection.getXAConn(JTAConnection.java:189)
		 at weblogic.jdbc.wrapper.JTAConnection.checkConnection(JTAConnection.java:64)
		 at weblogic.jdbc.wrapper.Connection.preInvocationHandler(Connection.java:83)
		 at weblogic.jdbc.wrapper.Connection.prepareStatement(Connection.java:473)
		 at org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:442)
		 at org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:368)
		 at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:105)
		 at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1561)
		 at org.hibernate.loader.Loader.doQuery(Loader.java:661)
		 at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
		 at org.hibernate.loader.Loader.loadEntity(Loader.java:1785)
		 at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:93)
		 at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:81)
		 at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:2730)
		 at org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:365)
		 at org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:346)
		 at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:123)
		 at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:82)
		 at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:891)
		 at org.hibernate.impl.SessionImpl.immediateLoad(SessionImpl.java:849)
		 at org.hibernate.proxy.AbstractLazyInitializer.initialize(AbstractLazyInitializer.java:62)
		 at org.hibernate.proxy.AbstractLazyInitializer.getImplementation(AbstractLazyInitializer.java:98)
		 at org.hibernate.proxy.CGLIBLazyInitializer.intercept(CGLIBLazyInitializer.java:158)
		 at ak.kille.dk80.core.data.model.actor.Actor$$EnhancerByCGLIB$$50efe36c_2.getDenom(<generated>)
		 at ak.kille.dk80.replicator.mdb.business.logic.impl.SubContractorParticipationReplicator.createSubContractorRelation(SubContractorParticipationReplicator.java:202)
		 at ak.kille.dk80.replicator.mdb.business.logic.impl.SubContractorParticipationReplicator.process(SubContractorParticipationReplicator.java:85)
		 at ak.kille.dk80.replicator.mdb.business.logic.impl.ReplicatorServiceImpl.replicateSubContractorParticipation(ReplicatorServiceImpl.java:96)
		 at ak.kille.dk80.replicator.mdb.MdbReader.replicate(MdbReader.java:131)
		 at ak.kille.dk80.replicator.mdb.MdbReader.onMessage(MdbReader.java:81)
		 at weblogic.ejb.container.internal.MDListener.execute(MDListener.java:466)
		 at weblogic.ejb.container.internal.MDListener.transactionalOnMessage(MDListener.java:371)
		 at weblogic.ejb.container.internal.MDListener.onMessage(MDListener.java:327)
		 at weblogic.jms.client.JMSSession.onMessage(JMSSession.java:4072)
		 at weblogic.jms.client.JMSSession.execute(JMSSession.java:3964)
		 at weblogic.jms.client.JMSSession$UseForRunnable.run(JMSSession.java:4490)
		 at weblogic.work.SelfTuningWorkManagerImpl$WorkAdapterImpl.run(SelfTuningWorkManagerImpl.java:464)
		 at weblogic.work.ExecuteThread.execute(ExecuteThread.java:200)
		 at weblogic.work.ExecuteThread.run(ExecuteThread.java:172)
 
		 at weblogic.jdbc.jta.DataSource.refreshXAConnAndEnlist(DataSource.java:1344)
		 at weblogic.jdbc.wrapper.JTAConnection.getXAConn(JTAConnection.java:189)
		 at weblogic.jdbc.wrapper.JTAConnection.checkConnection(JTAConnection.java:64)
		 at weblogic.jdbc.wrapper.Connection.preInvocationHandler(Connection.java:83)
		 at weblogic.jdbc.wrapper.Connection.prepareStatement(Connection.java:473)
		 at org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:442)
		 at org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:368)
		 at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:105)
		 at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1561)
		 at org.hibernate.loader.Loader.doQuery(Loader.java:661)
		 at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
		 at org.hibernate.loader.Loader.loadEntity(Loader.java:1785)
		 ... 27 more

As tu assez de connections de libre dans ton pool ?

Réponse

Nous avons développé une application qui tourne sous weblogic 8 comme config on a fixé le jta a 360 secondes.

A un moment donné nous avions aussi eu des problèmes de transactions le rollback se passait mal et du coup nous avoins eu des incohérence en base.

Ce qui peut expliquer c'est effectivement un pool insuffisant mais il faut aussi voir que c'est de la prod. il y a surement des batchs qui tournent, des requêtes d'exploitent etc... donc la machine peut être à genoux.

Après il y aussi des améliorations possibles retailler les pools de tes ressources (sql et jms), certains objets ne sont mis en cache alors qu'il le devrait ..

Nous n'avons pas réussi à faire du XA si tu as des infos sur comment le mettre en place je suis preneur.

Merci pour vos réponses (dsl de répondre aussi tard ;p)

Pour le pool, on m'a assuré que c'était bien configuré.. (ben oui, le truc, dans les grosses boites c'est qu'on n'a accès à rien...) Les environnements sont censés être identiques mais apparament pas...

Donc, on a découvert un problème de concurrence, ça a l'air de régler le prob. On croise les doigts.

Notre Time out est à 30 secondes, pour moi c'est déjà pas mal. On ne peut pas l'augmenter comme on veut car, pendant ce temps, les ressources sont bloquées. Enfin on va voir ce que ça dit avec la nouvelle version :-)

Pour ta question sur le XA je ne vois pas ce que tu veux :-) il faut configurer JMS pour utiliser des sessions XA et pareil pour tes datasources. Si tu veux plus d'infos, précise sur quoi :-)

Merci et Bon W-E