Discussion :

[MTTF - 8 ans]

Bonjour à tous,

J'ai développé un petit outil de workflow qui, pour résumer, prend des fichier Xml dans un répertoire, puis les fait traiter par une proc PLSQL avant d'archiver ces fichier.

Tout celà s'effectuant en multi-threads (8 dans l'exemple ci-dessous), j'utilise un pool de connections (chaque traitement de fichier impliquant un get ... close).
Tout fonctionne très bien avec des milliers de fichiers traités jusqu'au jour où, sans raison apparente, connection.close() "bloque"...

voici la définition de mon pool de connections :

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
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
 
public class DatabaseConnector {
	static private OracleDataSource ds = null;
	static boolean isInitialized = false;
	static private Logger logger = Logger.getLogger(DatabaseConnector.class.getName());
 
	/**
         * Initialize the data source used for connection requests.
         * @throws SQLException
         */
	synchronized static private void initialize() throws SQLException {
		try {
			if (ds != null) 
				shutdown();
 
			ds = new OracleDataSource();
			ds.setDriverType(Configurator.getProperty("driver"));
		    ds.setServerName(Configurator.getProperty("hostname"));
		    ds.setPortNumber((new Integer(Configurator.getProperty("portnumber"))).intValue());
		    ds.setDatabaseName(Configurator.getProperty("servicename")); // sid
		    ds.setUser(Configurator.getProperty("username"));
		    ds.setPassword(Configurator.getProperty("password"));
 
		    ds.setConnectionCachingEnabled(true);
		    Properties props = new Properties();
			props.put("MinLimit",Configurator.getProperty("MinLimit"));
			props.put("MaxLimit",Configurator.getProperty("MaxLimit"));
			props.put("InitialLimit",Configurator.getProperty("MinLimit"));
			props.put("InactivityTimeout",Configurator.getProperty("InactivityTimeout"));
			props.put("TimeToLiveTimeout",Configurator.getProperty("TimeToLiveTimeout"));
			props.put("AbandonedConnectionTimeout",Configurator.getProperty("AbandonedConnectionTimeout"));
		    ds.setConnectionCacheProperties(props);
		    ds.setLoginTimeout(60);
			isInitialized = true;
		} catch (SQLException e) {
			isInitialized = false;
			logger.severe("Error initializing database connector");
			logger.throwing(DatabaseConnector.class.getName(), "initialize", e);
			throw e;
		}
	}
 
	/**
         * Get a connection to the database from connection pool. 
         * If all connections are already used, this method wait for 
         * a connection to be released.
         * @return Database connection
         * @throws SQLException
         */
	synchronized static public Connection getConnection() throws SQLException {
		if (!isInitialized) {
			initialize();
		}
		try{
			Connection conn = ds.getConnection();
			return conn;
		} catch (SQLException e) {
			logger.severe("Error getting database connection");
			isInitialized = false;
			throw e;
		}
	}
 
	static public void closeConnection(Connection cnx){
		try{
			logger.info("Connection close request.");
			cnx.close();
			logger.info("Connection closed.");
		}catch(Exception e){
			logger.severe("closeConnection : " + e.getMessage());
		}
	}

Tout se passe donc très bien jusqu'au moment où dans mes logs j'obtiens :

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
 
Nov 2, 2007 4:31:51 PM ...DatabaseConnector closeConnection
INFO: Connection close request.
Nov 2, 2007 4:31:54 PM ...DatabaseConnector closeConnection
INFO: Connection close request.
Nov 2, 2007 4:31:55 PM ...DatabaseConnector closeConnection
INFO: Connection close request.
Nov 2, 2007 4:32:01 PM ...DatabaseConnector closeConnection
INFO: Connection close request.
Nov 2, 2007 4:32:36 PM ...DatabaseConnector closeConnection
INFO: Connection close request.
Nov 2, 2007 4:32:36 PM ...DatabaseConnector closeConnection
INFO: Connection close request.
Nov 2, 2007 4:33:08 PM ...DatabaseConnector closeConnection
INFO: Connection close request.
Nov 2, 2007 4:33:36 PM ...DatabaseConnector closeConnection
INFO: Connection close request.

et puis plus rien... les connections apparaissent alors (sous Toad) comme inactives, sans aucun lock et en état waiting!
Tout semble donc indiquer que l'instruction "cnx.close();" reste en attente de je ne sais quoi.
Une âme charitable aurait-elle une idée, une piste? Moi j'avoue que je sèche!

Merci par avance de votre aide!!!

[MTTF - 8 ans]

Hello,

Il me semble que mon problème pourrait venir du fait que je n'aie pas synchronisé la méthode "closeConnection(Connection cnx)". Je suis en train de tester en ajoutant un synchronized.

Quelqu'un peut-il confirmer que pour un datasource avec cache il est nécessaire de synchroniser la méthode close? (étonnant car il me semble que dans ce cas il existerait une methode closeConnection sur la classe OracleDataSource)

[OButterlin]

Je n'y crois pas trop, ça ressemble plutôt à un problème de driver JDBC ou peut-être le pool de connexions qui part en sucette...
Tu utilises quel pool de connexions ?

A+

[MTTF - 8 ans]

J'utilise les librairies oracle : oracle.jdbc.pool.OracleDataSource ... mais apparemment elles ne fonctionnent pas formidablement.

Je sais que le synchronize semble difficile à avaler mais je ne vois pas ce que ca peut être d'autre : pas de problème de mémoire que ce soit sur la JVM ou la BDD, les connexions sont inactives et mon programme freeze sur le cnx.close() (sachant que le execute() sur cette cnx s'est correctement déroulé).

Mes tests de charge sont toujours en cours après ajout du synchronize, je croise les doigts pour que ce soit ca même si je préfèrerais une explication plus rationnelle!!!

[MTTF - 8 ans]

Bon,

Suite à mes tests j'en arrive à la conclusion :
- le "synchronized" sur la méthode close() ne résoud pas le problème;
- changer de version du classes12.jar (pour différentes versions d'oracle : 10.1, 10.2 ...) ne résoud pas le problème non plus.

=> je suis plus que jamais bloqué et à l'écoute de toute idée!!!

[adiGuba]

Salut,


Je ne vois pas ce que le synchronized viendrait faire la dedans... a moins que tu ne partage une même connexion avec plusieurs thread...

Question : est-ce que tu fermes bien tous tes ResultSet/Statement ? On ne sait jamais cela pourrait bloquer la fermeture de la connexion...

a++

[OButterlin]

Quelles sont les valeurs pour ces attributs ?

Code :

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

1
2
3
4
5
6
7
 
props.put("MinLimit",Configurator.getProperty("MinLimit"));
props.put("MaxLimit",Configurator.getProperty("MaxLimit"));
props.put("InitialLimit",Configurator.getProperty("MinLimit"));
props.put("InactivityTimeout",Configurator.getProperty("InactivityTimeout"));
props.put("TimeToLiveTimeout",Configurator.getProperty("TimeToLiveTimeout"));
props.put("AbandonedConnectionTimeout",Configurator.getProperty("AbandonedConnectionTimeout"));

[MTTF - 8 ans]

En ce qui concerne les properties :

Code :

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

1
2
3
4
5
6
 
		<MinLimit>0</MinLimit>
		<MaxLimit>25</MaxLimit>
		<InactivityTimeout>300</InactivityTimeout>
		<TimeToLiveTimeout>1800</TimeToLiveTimeout>
		<AbandonedConnectionTimeout>900</AbandonedConnectionTimeout>

Mais je suis loin de la limite : 8 threads donc 8 connections utilisées et inactives (vérifié via Toad).
De plus, même au terme des timeouts, rien ne bouge, toujours bloqué sur le close()!


AdiGuba, effectivement le synchronized n'a pas grand chose à faire la dedans puisque chaque thread dispose de sa connection; mais comme lors d'un appel au close() la connection est remise en cache et que celui-ci est commun à toutes les connections.... dans mon désespoir j'ai imaginé que mon problème pouvait venir de là.

Concernant la fermeture du resultset et du statement j'ai la clause finally suivante (et pas de souci de mémoire à en croire prstat pour la JVM et les pool mémoire oracle sont OK également) :

Code :

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

1
2
3
4
5
6
7
8
9
10
 
} finally {
	try{
		stmt.getResultSet().close();
	}catch(Exception e){}
	try{
		stmt.close();
	}catch(Exception e){}
	DatabaseConnector.closeConnection(conn);
}

Je suis en train de modifier la création du pool de connections en remplacant:

ds.setConnectionCacheProperties(props);

par :

Code :

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

1
2
3
4
5
6
7
8
9
 
...
ds.setConnectionProperties(props);
OracleConnectionCacheManager connMgr =
    OracleConnectionCacheManager.getConnectionCacheManagerInstance();
props = new Properties();
props.setProperty("ValidateConnection", "true");
connMgr.createCache("MyCache", ds, props);
...

Comme mon pool fonctionnait sans passer par OracleConnectionCacheManager (avec des connections bien gérées en pool, les min-max et timeout bien pris en compte) , je ne pense pas que ce soit indispensable. Mais ayant vu un exemple de ce style sur Metalink... je teste!

[MTTF - 8 ans]

Re,

Je reviens vers vous pour annoncer que... ca ne fonctionne toujours pas ; par contre j'ai un peu avancé dans lidentification de mon problème puisqu'il semblerait que mon "close" bloque sur la methode :
Oracle/Jdbc/Pool/Oracleimplicitconnectioncache.Reusepooledconnection

Quelqu'un aurait-il déjà rencontré ce genre de problème et si c'est le cas, comment le contourner?!?

Voici la pile complète du thread bloqué (pstack) :

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
 
-----------------  lwp# 1498 / thread# 1498  --------------------
 ffffffff7f0ce9a4 lwp_cond_wait (10087a4c0, 10087a4a8, 0, 0)
 ffffffff7e3b2198 __1cNObjectMonitorGEnterI6MpnGThread__v_ (10087a4c0, ffffffff7eadfa30, 100296d68, ffffffff7e8d6672, ffffffff7ead75c8, 0) + 2a8
 ffffffff7e3e874c __1cNObjectMonitorGenter26MpnGThread__v_ (100296d68, f000, 0, 1008d38a0, 100296d88, 2) + 294
 ffffffff7e25d340 __1cSInterpreterRuntimeMmonitorenter6FpnKJavaThread_pnPBasicObjectLock__v_ (1008d38a0, 0, ffffffff4aafebb0, ffffffff7ea9b03c, ffffffff75005d20, ffffffff7ea0e000) + 1e0
 ffffffff7500bb70 * Oracle/Jdbc/Pool/Oracleimplicitconnectioncache.Reusepooledconnection(Ljavax/Sql/Pooledconnection;)V+0
 ffffffff75005810 * oracle/jdbc/pool/OracleConnectionCacheEventListener.connectionClosed(Ljavax/sql/ConnectionEvent;)V+18 (line 61)
 ffffffff75005d20 * oracle/jdbc/pool/OraclePooledConnection.callImplicitCacheListener(I)V+49 (line 504)
 ffffffff75005810 * oracle/jdbc/pool/OraclePooledConnection.logicalCloseForImplicitConnectionCache()V+22 (line 425)
 ffffffff75005810 * oracle/jdbc/pool/OraclePooledConnection.logicalClose()V+8 (line 441)
 ffffffff75005810 * oracle/jdbc/driver/LogicalConnection.closeInternal(Z)V+61 (line 219)
 ffffffff75005810 * oracle/jdbc/driver/LogicalConnection.close()V+2 (line 192)
 ffffffff75005d20 * .../common/DatabaseConnector.closeConnection(Ljava/sql/Connection;)V+9 (line 120)
 ffffffff750f016c * C2IAdapter
 ffffffff75142728 * *.../core/Launcher.run()V+671 (line 317)
 ffffffff750b4b90 * I2CAdapter
 ffffffff7500023c * StubRoutines (1)
 ffffffff7e29c180 __1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_ (1, 1008d38a0, a, ffffffff6e10e790, ffffffff4aaff648, 10072a590) + 5f0
 ffffffff7e3d03ac __1cJJavaCallsMcall_virtual6FpnJJavaValue_nGHandle_nLKlassHandle_nMsymbolHandle_5pnGThread__v_ (ffffffff6e10e790, 1008d38a0, ffffffff50292170, ffffffff7eacbe98, ffffffff7eacc038, ffffffff4aaff808) + 164
 ffffffff7e3eecdc __1cMthread_entry6FpnKJavaThread_pnGThread__v_ (ffffffff7eab91d8, 1008d38a0, e000, ffffffff4f842bc0, ffffffff6e10e790, ffffffff7ea0e000) + 124
 ffffffff7e3e91fc __1cKJavaThreadDrun6M_v_ (1008d38a0, f000, ffffffff7eaa5bd4, 0, 0, ffffffff7ea0e000) + 2ac
 ffffffff7e7a9bc8 __1cG_start6Fpv_0_ (1008d38a0, d800, b000, b240, ffffffff7eab0ddc, ffffffff7ea0e000) + 210
 ffffffff7f0cd69c _lwp_start (0, 0, 0, 0, 0, 0)

[MTTF - 8 ans]

Bonjour,

Il semblerait que l'origine de mon problème soit très, très stupide... J'ai utilisé pour api oracle le classes12.jar en lieu et place du ojdbc14.jar (je suis en 1.5).

Le symptome est quand même vicieux pour en arriver à cette conclusion!