Problème de DataSource

**CharlSka** · 24/06/2009, 18h50

Bonjour à tous,

J'ai un problème avec la datasource de JONAS. (du moins il semblerait

)
En fait en l'état actuel, lorsqu'on a une coupure de la base de données (redémarrage par exemple) les requêtes qui suivent renvoient une erreur du style :

Code :

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
    ***  2009-06-24 16:38:58,965    WARN    [JDBCExceptionReporter]    SQL Error: 0, SQLState: 08S01    [http-9000-Processor25]    C079C8C600500E6B4660B9DC2F92115F.jonas-1
    ***  2009-06-24 16:38:58,965    ERROR    [JDBCExceptionReporter]    Communications link failure due to underlying exception:
 
    ** BEGIN NESTED EXCEPTION **
 
    java.net.SocketException
    MESSAGE: Software caused connection abort: socket write error
 
    STACKTRACE:
 
    java.net.SocketException: Software caused connection abort: socket write error
        at java.net.SocketOutputStream.socketWrite0(Native Method)
        at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:92)
        at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
        at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65)
        at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:123)
        at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:2616)
        at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:2547)
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1512)
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1622)
        at com.mysql.jdbc.Connection.execSQL(Connection.java:2376)
        at com.mysql.jdbc.Connection.execSQL(Connection.java:2297)
        at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1860)
        at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:1705)
        at org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:186)
        at org.hibernate.loader.Loader.getResultSet(Loader.java:1668)
        at org.hibernate.loader.Loader.doQuery(Loader.java:662)
        at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
        at org.hibernate.loader.Loader.doList(Loader.java:2144)
        at org.hibernate.loader.Loader.listUsingQueryCache(Loader.java:2060)
        at org.hibernate.loader.Loader.list(Loader.java:2020)
        at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:393)
        at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:338)
        at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172)
        at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1121)
        at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
        at com.iv4.accessbean.hibernate.GestionMobileAccessBeanImpl.getReunions(GestionMobileAccessBeanImpl.java:73

Puis au bout de plusieurs erreur (apparement autant qu'il y a de connection existante dans le pool) l'erreur devient

Code :

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

1
2
3
4
5
    ***  2009-06-24 16:40:20,747    WARN    [JDBCExceptionReporter]    SQL Error: 0, SQLState: 08003    [http-9000-Processor24]    C079C8C600500E6B4660B9DC2F92115F.jonas-1
    ***  2009-06-24 16:40:20,747    ERROR    [JDBCExceptionReporter]    No operations allowed after connection closed.    [http-9000-Processor24]    C079C8C600500E6B4660B9DC2F92115F.jonas-1
    ***  2009-06-24 16:40:20,762    ERROR    [TomcatBridge]    Erreur technique BV dans getRacingContext(24/06/2009 12:00:00)    [http-9000-Processor24]    C079C8C600500E6B4660B9DC2F92115F.jonas-1
    com.iv4.exception.BVTechException
        at com.iv4.accessbean.bv.InterfaceBV.getReunions(InterfaceBV.java:756

Et il est necessaire de relancer JONAS pour que ca remarche.
La configuration actuelle du datasource est la suivante :

Code :

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
    datasource.name                 jdbc/LiferayPool
    datasource.url                  jdbc:mysql://server/base?useUnicode=true&amp;characterEncoding=UTF-8
    datasource.classname            com.mysql.jdbc.Driver
    datasource.username             iv4user
    datasource.password             iv4pass
    datasource.mapper               rdb.mysql
 
    #  JDBC connection checking level.
    #     0 = no special checking
    #     1 = check physical connection is still open before reusing it
    #     2 = try every connection before reusing it
    jdbc.connchecklevel    0
 
    #  Max age for jdbc connections
    #  nb of minutes a connection can be kept in the pool
    # By default mySQL has a timeout every 8 hours, use a value of 7h
    jdbc.connmaxage        420
 
    # Maximum time (in mn) a connection can be left busy.
    # If the caller has not issued a close() during this time, the connection
    # will be closed automatically.
    jdbc.maxopentime    15
 
    #  Test statement
    jdbc.connteststmt    select 1
 
    # JDBC Connection Pool size.
    # Limiting the max pool size avoids errors from database.
    jdbc.minconpool        10
    jdbc.maxconpool        50
 
    # Sampling period for JDBC monitoring :
    # nb of seconds between 2 measures.
    jdbc.samplingperiod    30
 
    # Maximum time (in seconds) to wait for a connection in case of shortage.
    # This may occur only when maxconpool is reached.
    jdbc.maxwaittime    10
 
    # Maximum of concurrent waiters for a JDBC Connection
    # This may occur only when maxconpool is reached.
    jdbc.maxwaiters        100
 
    # Maximum number of Prepare Statements cached in a Connection
    jdbc.pstmtmax    120

J'ai réussi à résoudre le problème en modifiant la configuration du datasource avec

Code :

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

    jdbc.connchecklevel    2

Mais niveau performance

, je doute que ce soit très efficace !

J'ai aussi essayé avec

Code :

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

    jdbc.connchecklevel    1

Le Datasource arrive a refournir des connections valide, mais on dirait qu'il vide sont pool de ses connection foireuses avant de rouvrir de nouvelles connections ... Ce qui n'est toujours pas satisfaisant.

Donc je ne sais pas si ce genre de problème vous parle ?
Est-ce normal que le DataSource ne soit pas capable de fournir de nouvelles connections après une perte de la BDD !?
Ou est-ce que que vous avez une idée de ce qui pourrait provoquer ce type de dysfonctionnement ?

D'avance merci,

**kalysto** · 24/06/2009, 20h28

Deja, je trouve bizarre que dans ta stacktrace, tu ne trouves aucune classe de JOnAS (org.objectweb.jonas...) ...
Tu configures bien Hibernate pour qu'il utilise le nom JNDI de ta DataSource (jndi/LiferayPool dans ton cas) ?

Si tu veux garder le conn checklevel a 0, il faudrait savoir si hibernate peut reagir aux exceptions et refaire une requete quand ca foire.

Si tu mets a 2, en effet, c'est mois performant, mais tout depend de la requete de test que tu fais executer. Je sais que pour Oracle, il y a une requete speciale (recommandée par Oracle) pour ca.

De toute facon, une fois que la connection avec la base est cassée, les connections seront discarded, et donc c'est normal de vider progressivement ton pool et remplacer avec des connexions neuves.

Dans tous les cas, tu auras un cout, plus ou moins important.

A toi de voir ce qui correspond le mieux a ton application.

A mon avis, le level a 1 devrait etre suffisant.

**CharlSka** · 25/06/2009, 08h59

Oui, je confirme que Hibernate est bien relié au nom JNDI, mais il y a quelquechose qui me chagrine un peu ...
dans applicationContext.xml j'ai

Code :

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

1
2
3
4
5
6
7
8
9
10
11
12
13
<jee:jndi-lookup id="liferayDS" jndi-name="java:comp/env/jdbc/LiferayPool" />
<bean id="liferayDSProxy" class="org.springframework.jdbc.datasource.LazyConnectionDataSourceProxy" lazy-init="true">
	<property name="targetDataSource" ref="liferayDS" />
</bean>
 
<bean id="sessionFactory" class="org.springframework.orm.hibernate3.LocalSessionFactoryBean">
	<property name="configLocation">
		<value>classpath:com/iv4/config/spring/hibernate.cfg.xml</value>
	</property>
	<property name="dataSource">
		<ref bean="liferayDSProxy" />
	</property>
</bean>

et dans le hibernate.cfg.xml

Code :

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
<hibernate-configuration>
	<session-factory>
		<property name="hibernate.connection.datasource">java:comp/env/jdbc/LiferayPool</property>
		<property name="hibernate.connection.autocommit">false</property>
		<property name="hibernate.jdbc.batch_size">10</property>
		<property name="hibernate.cache.provider_class">org.hibernate.cache.EhCacheProvider</property>
		<property name="hibernate.cache.use_query_cache">true</property>
		<property name="hibernate.cache.use_second_level_cache">true</property>
		<property name="hibernate.cache.use_structured_entries">false</property>
		<property name="hibernate.transaction.factory_class">org.hibernate.transaction.JDBCTransactionFactory</property>
		<property name="hibernate.dialect">org.hibernate.dialect.MySQL5InnoDBDialect</property>
		<property name="hibernate.show_sql">false</property>
		<property name="hibernate.max_fetch_depth">2</property>
		<property name="hibernate.default_batch_fetch_size">4</property>
		<property name="hibernate.order_updates">true</property>
		<property name="hibernate.generate_statistics">true</property>
 
		<property name="hibernate.cache.provider_configuration_file_resource_path">com/iv4/config/ehcache.xml</property>
 
		[... mappings ...]
 
	</session-factory>
</hibernate-configuration>

J'ai l'impression que la liaison est faite de deux manières différentes. Une fois dans le applicationContext.xml et une fois dans le hibernate.cfg.xml. Et je ne sais pas laquelle est réellement utilisée

.

Cela dit ta remarque sur la stacktrace sans trace jonas me fait dire qu'il y a un problème ...

Je fais quelques tests et je repasse dans la journée donner des nouvelles

**CharlSka** · 25/06/2009, 10h14

J'ai re-testé en m'assurant que hibernate soit bien directement relié au DataSource défini dans le JNDI en commentant sa redéfinition dans l'applicationContext.xml :

Code :

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

1
2
3
4
5
6
7
8
9
10
11
12
13
<jee:jndi-lookup id="liferayDS" jndi-name="java:comp/env/jdbc/LiferayPool" />
<bean id="liferayDSProxy" class="org.springframework.jdbc.datasource.LazyConnectionDataSourceProxy" lazy-init="true">
	<property name="targetDataSource" ref="liferayDS" />
</bean>

<bean id="sessionFactory" class="org.springframework.orm.hibernate3.LocalSessionFactoryBean">
	<property name="configLocation">
		<value>classpath:com/iv4/config/spring/hibernate.cfg.xml</value>
	</property>
	<!--<property name="dataSource">
		<ref bean="liferayDSProxy" />
	</property>-->
</bean>

J'ai également corrigé la référence au JNDI faite dans hibernate.cfg.xml pour que ca fonctionne.

Code :

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

1
2
3
4
5
6
<hibernate-configuration>
	<session-factory>
		<property name="hibernate.connection.datasource">jdbc/LiferayPool</property>
		[...]		
	</session-factory>
</hibernate-configuration>

Malheureusement, le comportement reste le même, à savoir qu'avec

Code :

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

1
2
 
jdbc.connchecklevel    0

la perte de la base plante l'application avec l'erreur suivante (avec ici une référence à JONAS)

Code :

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
***  2009-06-25 09:46:07,802	ERROR	[JDBCTransaction]	JDBC begin failed	[http-9000-Processor24]	73504A252FF83C8FA46F6BF8D2446EF9.jonas-1
com.mysql.jdbc.CommunicationsException: Communications link failure due to underlying exception: 

** BEGIN NESTED EXCEPTION ** 

java.io.EOFException

STACKTRACE:

java.io.EOFException
	at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:1842)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2288)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:2784)
	at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1531)
	at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1622)
	at com.mysql.jdbc.Connection.execSQL(Connection.java:2370)
	at com.mysql.jdbc.Connection.setAutoCommit(Connection.java:525)
	at org.objectweb.jonas.jdbc_xa.ConnectionImpl.setAutoCommit(ConnectionImpl.java:339)
	at org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:63)
	at org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1326)
	at org.springframework.orm.hibernate3.HibernateTransactionManager.doBegin(HibernateTransactionManager.java:496)
	at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:322)
	at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:255)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:102)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:210)
	at $Proxy6.getReunions(Unknown Source)
	at com.iv4.command.MobileGetReunionsCommand.performExecute(MobileGetReunionsCommand.java:83)

avec

Code :

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

1
2
 
jdbc.connchecklevel    1

l'application reste innaccessible tant que toutes les connections du pool n'ont pas été testées ...
Ce qui veut dire, si 50 Connections sont dans le pool, 50 personnes vont avoir un message d'erreur avant que l'application soit à nouveau disponible ...

et avec

Code :

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