Fuite de connexions

Bonjour à tous,

Voila, il semble que j'ai une fuite de connexion quelque part. Pour reproduire le problème, j'ai fais un petit TU.

Au niveau architecture, on a une base de données MySQL, et du JPA.
(Autre petit point : j'arrive en intercontrat et je tombe sur ce projet développé par des stagiaires, et d'autres interco ... bref, on passera volontiers à côté des réflexions sur l'architecture et autres questions qui sont importantes mais dont ce topic n'est pas le sujet).

Alors, voici le contenu de mon test :

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
 
@Test
public void testFuiteConnexion() { // Point d'entrée
	@SuppressWarnings("static-access")
 
	// récupérer l'instance EntityManager afin d'effectué un rollback en cas d'echec
	EntityManager em = GroupesNotesDao.entityManager();
 
	// récupérer l'ID du groupe que vous venez de crée depuis l'IHM
	// groupe 19 exist dans le scchema
	String groupId = "19";			
 
	List<Integer> listCompetenciesAdd = new ArrayList<Integer>();
	int nbCompetences = 30;
 
	// choix arbitraire des ID de COMPETENCES entre 1 et 100
	Random rd = new Random();
	for (int i = 0; i < nbCompetences; i++) {
		listCompetenciesAdd.add((rd.nextInt(100) + 1));
	}
 
	// Ajout compétence depuis la list : listCompetenciesAdd
 
	for (int i = 0; i< listCompetenciesAdd.size(); i++) {
		System.out.println("[testFuiteConnexion] Ajout N° " + (i+1));
	GroupesNotesManager.addCompetence(em, groupId,
			("" + listCompetenciesAdd.get(i)));
	}
	// à titre indicatif : le resultat est toujours vrai
	assertEquals(listCompetenciesAdd.size(),nbCompetences);
 
	em.close();
 
}

Voici le code permettant d'accéder à l'entityManager :

Code:

1
2
3
4
5
 
public static final EntityManager entityManager() {
	//EMF est un EntityManagerFactory en mode Singleton
	return EMF.get().createEntityManager();
}

Le code de GroupeNoteManager.addCompetence :

Code:

1
2
3
4
5
6
7
8
9
10
11
12
13
 
public static boolean addCompetence(EntityManager em, final String groupId,
		final String newCompId) {
 
	boolean result = false;
	List<CollaborateurGroupe> listCollaborateurGroupe = new ArrayList<CollaborateurGroupe>();
	List<GroupesNotes> listGroupesNotes = new ArrayList<GroupesNotes>();
 
	[...]
	GroupesNotesDao.updateListGroupeNotes(em, listGroupesNotes);
	result = true;
	return result;
}

Et enfin GroupeNoteDao.updateListGroupeNotes

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
 
public final static boolean updateListGroupeNotes(EntityManager em, 
			final List<GroupesNotes> listGN) {
			boolean addValidate = false;
 
		try {
			GroupesNotesManager.showGN(listGN);
			EntityTransaction tx = em.getTransaction();
			tx.begin();
			for (int i = 0; i < listGN.size(); i++) {
				em.persist(listGN.get(i));
			}
			tx.commit();
 
			addValidate = true;	
			//em.getTransaction().commit();
			GroupesNotesManager.showGN(listGN);
 
		} catch (Exception e) {
			LOGGER.error(
					"[GroupesNotesDao],[updateListGroupeNotes],[" + e.getMessage()
							+ "]", e);
			addValidate = false;
			em.getTransaction().rollback();
		}
		return addValidate;
	}

Et enfin le log que ça me crache (attention, c'est hyper verbeux)

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
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
 
[testFuiteConnexion] Ajout N° 10
2013-09-25 16:22:34,142 DEBUG [org.hibernate.jdbc.AbstractBatcher:410] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2013-09-25 16:22:34,142 DEBUG [org.hibernate.jdbc.ConnectionManager:444] opening JDBC connection
2013-09-25 16:22:34,143 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,143 DEBUG [org.hibernate.SQL:111] select groupescol0_.ID as ID4_, groupescol0_.DATECREATION as DATECREA2_4_, groupescol0_.DATEFIN as DATEFIN4_, groupescol0_.NOM as NOM4_, groupescol0_.VERSION as VERSION4_ from GroupesCollaborateurs groupescol0_ where groupescol0_.ID=? limit ?
2013-09-25 16:22:34,143 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:179] com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache ----> CACHE HIT
2013-09-25 16:22:34,143 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:196] checkoutStatement: com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 1; num connections: 7; num keys: 50
2013-09-25 16:22:34,144 DEBUG [org.hibernate.jdbc.AbstractBatcher:426] about to open ResultSet (open ResultSets: 0, globally: 0)
2013-09-25 16:22:34,145 DEBUG [org.hibernate.loader.Loader:1322] result row: EntityKey[sii.hippoComp.server.domain.GroupesCollaborateurs#19]
2013-09-25 16:22:34,145 DEBUG [org.hibernate.jdbc.AbstractBatcher:433] about to close ResultSet (open ResultSets: 1, globally: 1)
2013-09-25 16:22:34,145 DEBUG [org.hibernate.jdbc.AbstractBatcher:418] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2013-09-25 16:22:34,145 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:271] checkinStatement(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,145 DEBUG [org.hibernate.jdbc.ConnectionManager:427] aggressively releasing JDBC connection
2013-09-25 16:22:34,145 DEBUG [org.hibernate.jdbc.ConnectionManager:464] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2013-09-25 16:22:34,145 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:297] checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,146 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,146 DEBUG [org.hibernate.engine.StatefulPersistenceContext:893] initializing non-lazy collections
2013-09-25 16:22:34,146 DEBUG [org.hibernate.jdbc.ConnectionManager:427] aggressively releasing JDBC connection
2013-09-25 16:22:34,146 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:297] checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,146 DEBUG [org.hibernate.jdbc.AbstractBatcher:410] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2013-09-25 16:22:34,146 DEBUG [org.hibernate.jdbc.ConnectionManager:444] opening JDBC connection
2013-09-25 16:22:34,146 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,146 DEBUG [org.hibernate.SQL:111] select collaborat0_.ID as ID1_, collaborat0_.COLLABORATEURS_ID as COLLABOR5_1_, collaborat0_.DATEENTREE as DATEENTREE1_, collaborat0_.DATESORTIE as DATESORTIE1_, collaborat0_.GROUPESCOLLABORATEURS_ID as GROUPESC6_1_, collaborat0_.VERSION as VERSION1_ from CollaborateurGroupe collaborat0_ where collaborat0_.GROUPESCOLLABORATEURS_ID=?
2013-09-25 16:22:34,147 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:179] com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache ----> CACHE HIT
2013-09-25 16:22:34,147 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:196] checkoutStatement: com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 1; num connections: 7; num keys: 50
2013-09-25 16:22:34,148 DEBUG [org.hibernate.jdbc.AbstractBatcher:426] about to open ResultSet (open ResultSets: 0, globally: 0)
2013-09-25 16:22:34,149 DEBUG [org.hibernate.loader.Loader:1322] result row: EntityKey[sii.hippoComp.server.domain.CollaborateurGroupe#253]
2013-09-25 16:22:34,149 DEBUG [org.hibernate.loader.Loader:1322] result row: EntityKey[sii.hippoComp.server.domain.CollaborateurGroupe#254]
2013-09-25 16:22:34,149 DEBUG [org.hibernate.jdbc.AbstractBatcher:433] about to close ResultSet (open ResultSets: 1, globally: 1)
2013-09-25 16:22:34,149 DEBUG [org.hibernate.jdbc.AbstractBatcher:418] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2013-09-25 16:22:34,150 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:271] checkinStatement(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,150 DEBUG [org.hibernate.jdbc.ConnectionManager:427] aggressively releasing JDBC connection
2013-09-25 16:22:34,151 DEBUG [org.hibernate.jdbc.ConnectionManager:464] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2013-09-25 16:22:34,151 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:297] checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,151 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,151 DEBUG [org.hibernate.engine.StatefulPersistenceContext:893] initializing non-lazy collections
2013-09-25 16:22:34,151 DEBUG [org.hibernate.jdbc.ConnectionManager:427] aggressively releasing JDBC connection
2013-09-25 16:22:34,151 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:297] checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,151 DEBUG [sii.hippoComp.server.managerDao.GroupesNotesManager:318] *** - collaborateurDansGroupePourUneCompetence - ***
2013-09-25 16:22:34,151 DEBUG [sii.hippoComp.server.managerDao.GroupesNotesManager:318] *** - collaborateurDansGroupePourUneCompetence - ***
2013-09-25 16:22:34,152 DEBUG [org.hibernate.jdbc.AbstractBatcher:410] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2013-09-25 16:22:34,152 DEBUG [org.hibernate.jdbc.ConnectionManager:444] opening JDBC connection
2013-09-25 16:22:34,152 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,152 DEBUG [org.hibernate.SQL:111] select histnotes0_.ID as ID6_, histnotes0_.ACTION as ACTION6_, histnotes0_.COLLABORATEURS_ID as COLLABOR7_6_, histnotes0_.COMPETENCES_ID as COMPETEN8_6_, histnotes0_.DATEDEBUT as DATEDEBUT6_, histnotes0_.DATEFIN as DATEFIN6_, histnotes0_.NOTE as NOTE6_, histnotes0_.VERSION as VERSION6_ from HistNotes histnotes0_ where histnotes0_.COMPETENCES_ID=? and histnotes0_.COLLABORATEURS_ID=? order by DATEFIN ASC
2013-09-25 16:22:34,152 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:179] com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache ----> CACHE HIT
2013-09-25 16:22:34,152 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:196] checkoutStatement: com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 1; num connections: 7; num keys: 50
2013-09-25 16:22:34,154 DEBUG [org.hibernate.jdbc.AbstractBatcher:426] about to open ResultSet (open ResultSets: 0, globally: 0)
2013-09-25 16:22:34,154 DEBUG [org.hibernate.jdbc.AbstractBatcher:433] about to close ResultSet (open ResultSets: 1, globally: 1)
2013-09-25 16:22:34,154 DEBUG [org.hibernate.jdbc.AbstractBatcher:418] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2013-09-25 16:22:34,154 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:271] checkinStatement(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,155 DEBUG [org.hibernate.jdbc.ConnectionManager:427] aggressively releasing JDBC connection
2013-09-25 16:22:34,155 DEBUG [org.hibernate.jdbc.ConnectionManager:464] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2013-09-25 16:22:34,155 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:297] checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,155 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,155 DEBUG [org.hibernate.engine.StatefulPersistenceContext:893] initializing non-lazy collections
2013-09-25 16:22:34,155 DEBUG [org.hibernate.jdbc.ConnectionManager:427] aggressively releasing JDBC connection
2013-09-25 16:22:34,155 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:297] checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,156 DEBUG [org.hibernate.jdbc.AbstractBatcher:410] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2013-09-25 16:22:34,156 DEBUG [org.hibernate.jdbc.ConnectionManager:444] opening JDBC connection
2013-09-25 16:22:34,156 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,156 DEBUG [org.hibernate.SQL:111] select notes0_.ID as ID7_, notes0_.COLLABORATEURS_ID as COLLABOR6_7_, notes0_.COMPETENCES_ID as COMPETEN7_7_, notes0_.DATECREATION as DATECREA2_7_, notes0_.DATEMODIFICATION as DATEMODI3_7_, notes0_.NOTE as NOTE7_, notes0_.VERSION as VERSION7_ from Notes notes0_ where notes0_.COMPETENCES_ID=? and notes0_.COLLABORATEURS_ID=? order by DATEMODIFICATION ASC limit ?
2013-09-25 16:22:34,156 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:179] com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache ----> CACHE HIT
2013-09-25 16:22:34,156 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:196] checkoutStatement: com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 1; num connections: 7; num keys: 50
2013-09-25 16:22:34,158 DEBUG [org.hibernate.jdbc.AbstractBatcher:426] about to open ResultSet (open ResultSets: 0, globally: 0)
2013-09-25 16:22:34,158 DEBUG [org.hibernate.jdbc.AbstractBatcher:433] about to close ResultSet (open ResultSets: 1, globally: 1)
2013-09-25 16:22:34,158 DEBUG [org.hibernate.jdbc.AbstractBatcher:418] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2013-09-25 16:22:34,158 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:271] checkinStatement(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,158 DEBUG [org.hibernate.jdbc.ConnectionManager:427] aggressively releasing JDBC connection
2013-09-25 16:22:34,158 DEBUG [org.hibernate.jdbc.ConnectionManager:464] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2013-09-25 16:22:34,159 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:297] checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,159 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,159 DEBUG [org.hibernate.engine.StatefulPersistenceContext:893] initializing non-lazy collections
2013-09-25 16:22:34,159 DEBUG [org.hibernate.jdbc.ConnectionManager:427] aggressively releasing JDBC connection
2013-09-25 16:22:34,159 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:297] checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,159 DEBUG [org.hibernate.impl.SessionImpl:265] opened session at timestamp: 13801189541
2013-09-25 16:22:34,160 DEBUG [org.hibernate.jdbc.AbstractBatcher:410] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2013-09-25 16:22:34,160 DEBUG [org.hibernate.jdbc.ConnectionManager:444] opening JDBC connection
2013-09-25 16:22:34,160 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,160 DEBUG [org.hibernate.SQL:111] select competence0_.ID as ID3_, competence0_.DATECREATION as DATECREA2_3_, competence0_.DATEMODIFICATION as DATEMODI3_3_, competence0_.NOM as NOM3_, competence0_.THEME_ID as THEME6_3_, competence0_.VERSION as VERSION3_ from Competences competence0_ where competence0_.ID=? limit ?
2013-09-25 16:22:34,160 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:179] com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache ----> CACHE HIT
2013-09-25 16:22:34,160 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:196] checkoutStatement: com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 1; num connections: 7; num keys: 50
2013-09-25 16:22:34,162 DEBUG [org.hibernate.jdbc.AbstractBatcher:426] about to open ResultSet (open ResultSets: 0, globally: 0)
2013-09-25 16:22:34,162 DEBUG [org.hibernate.loader.Loader:1322] result row: EntityKey[sii.hippoComp.server.domain.Competences#67]
2013-09-25 16:22:34,162 DEBUG [org.hibernate.jdbc.AbstractBatcher:433] about to close ResultSet (open ResultSets: 1, globally: 1)
2013-09-25 16:22:34,162 DEBUG [org.hibernate.jdbc.AbstractBatcher:418] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2013-09-25 16:22:34,163 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:271] checkinStatement(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,163 DEBUG [org.hibernate.jdbc.ConnectionManager:427] aggressively releasing JDBC connection
2013-09-25 16:22:34,163 DEBUG [org.hibernate.jdbc.ConnectionManager:464] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2013-09-25 16:22:34,163 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:297] checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,163 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,163 DEBUG [org.hibernate.engine.TwoPhaseLoad:130] resolving associations for [sii.hippoComp.server.domain.Competences#67]
2013-09-25 16:22:34,164 DEBUG [org.hibernate.loader.Loader:2022] loading entity: [sii.hippoComp.server.domain.Themes#14]
2013-09-25 16:22:34,165 DEBUG [org.hibernate.jdbc.AbstractBatcher:410] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2013-09-25 16:22:34,165 DEBUG [org.hibernate.jdbc.ConnectionManager:444] opening JDBC connection
2013-09-25 16:22:34,165 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:554] acquire test -- pool is already maxed out. [managed: 10; max: 10]
2013-09-25 16:22:34,166 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1291] awaitAvailable(): com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb
2013-09-25 16:22:34,166 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,165 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:297] checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,166 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,166 DEBUG [org.hibernate.SQL:111] select themes0_.ID as ID11_1_, themes0_.CATEGORIE_ID as CATEGORIE6_11_1_, themes0_.DATECREATION as DATECREA2_11_1_, themes0_.DATEMODIFICATION as DATEMODI3_11_1_, themes0_.NOM as NOM11_1_, themes0_.VERSION as VERSION11_1_, categories1_.ID as ID0_0_, categories1_.DATECREATION as DATECREA2_0_0_, categories1_.DATEMODIFICATION as DATEMODI3_0_0_, categories1_.NOM as NOM0_0_, categories1_.VERSION as VERSION0_0_ from Themes themes0_ inner join Categories categories1_ on themes0_.CATEGORIE_ID=categories1_.ID where themes0_.ID=?
2013-09-25 16:22:34,167 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:179] com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache ----> CACHE HIT
2013-09-25 16:22:34,167 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:196] checkoutStatement: com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 1; num connections: 7; num keys: 50
2013-09-25 16:22:34,169 DEBUG [org.hibernate.jdbc.AbstractBatcher:426] about to open ResultSet (open ResultSets: 0, globally: 0)
2013-09-25 16:22:34,170 DEBUG [org.hibernate.loader.Loader:1322] result row: EntityKey[sii.hippoComp.server.domain.Categories#4], EntityKey[sii.hippoComp.server.domain.Themes#14]
2013-09-25 16:22:34,170 DEBUG [org.hibernate.jdbc.AbstractBatcher:433] about to close ResultSet (open ResultSets: 1, globally: 1)
2013-09-25 16:22:34,170 DEBUG [org.hibernate.jdbc.AbstractBatcher:418] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2013-09-25 16:22:34,170 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:271] checkinStatement(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,170 DEBUG [org.hibernate.jdbc.ConnectionManager:427] aggressively releasing JDBC connection
2013-09-25 16:22:34,171 DEBUG [org.hibernate.jdbc.ConnectionManager:464] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2013-09-25 16:22:34,171 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:297] checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,171 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,171 DEBUG [org.hibernate.engine.TwoPhaseLoad:130] resolving associations for [sii.hippoComp.server.domain.Categories#4]
2013-09-25 16:22:34,171 DEBUG [org.hibernate.engine.TwoPhaseLoad:255] done materializing entity [sii.hippoComp.server.domain.Categories#4]
2013-09-25 16:22:34,172 DEBUG [org.hibernate.engine.TwoPhaseLoad:130] resolving associations for [sii.hippoComp.server.domain.Themes#14]
2013-09-25 16:22:34,172 DEBUG [org.hibernate.engine.TwoPhaseLoad:255] done materializing entity [sii.hippoComp.server.domain.Themes#14]
2013-09-25 16:22:34,172 DEBUG [org.hibernate.loader.Loader:2050] done entity load
2013-09-25 16:22:34,172 DEBUG [org.hibernate.engine.TwoPhaseLoad:255] done materializing entity [sii.hippoComp.server.domain.Competences#67]
2013-09-25 16:22:34,172 DEBUG [org.hibernate.engine.StatefulPersistenceContext:893] initializing non-lazy collections
2013-09-25 16:22:34,172 DEBUG [org.hibernate.jdbc.ConnectionManager:427] aggressively releasing JDBC connection
2013-09-25 16:22:34,173 DEBUG [org.hibernate.impl.SessionImpl:265] opened session at timestamp: 13801189541
2013-09-25 16:22:34,173 DEBUG [org.hibernate.jdbc.AbstractBatcher:410] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2013-09-25 16:22:34,173 DEBUG [org.hibernate.jdbc.ConnectionManager:444] opening JDBC connection
2013-09-25 16:22:34,173 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:554] acquire test -- pool is already maxed out. [managed: 10; max: 10]
2013-09-25 16:22:34,173 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1291] awaitAvailable(): com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb
2013-09-25 16:22:34,174 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:297] checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,174 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,174 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,174 DEBUG [org.hibernate.SQL:111] select collaborat0_.ID as ID2_, collaborat0_.ADRESSEMAIL as ADRESSEM2_2_, collaborat0_.DATE as DATE2_, collaborat0_.DATECREATION as DATECREA4_2_, collaborat0_.DATEMODIFICATION as DATEMODI5_2_, collaborat0_.DATERELANCE as DATERELA6_2_, collaborat0_.IDENTIFIANT as IDENTIFI7_2_, collaborat0_.MOTDEPASSE as MOTDEPASSE2_, collaborat0_.NOM as NOM2_, collaborat0_.PATH as PATH2_, collaborat0_.PRENOM as PRENOM2_, collaborat0_.ROLE_ID as ROLE13_2_, collaborat0_.VERSION as VERSION2_ from Collaborateurs collaborat0_ where collaborat0_.ID=? limit ?
2013-09-25 16:22:34,174 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:179] com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache ----> CACHE HIT
2013-09-25 16:22:34,174 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:196] checkoutStatement: com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 1; num connections: 7; num keys: 50
2013-09-25 16:22:34,176 DEBUG [org.hibernate.jdbc.AbstractBatcher:426] about to open ResultSet (open ResultSets: 0, globally: 0)
2013-09-25 16:22:34,177 DEBUG [org.hibernate.loader.Loader:1322] result row: EntityKey[sii.hippoComp.server.domain.Collaborateurs#47]
2013-09-25 16:22:34,177 DEBUG [org.hibernate.jdbc.AbstractBatcher:433] about to close ResultSet (open ResultSets: 1, globally: 1)
2013-09-25 16:22:34,177 DEBUG [org.hibernate.jdbc.AbstractBatcher:418] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2013-09-25 16:22:34,177 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:271] checkinStatement(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,177 DEBUG [org.hibernate.jdbc.ConnectionManager:427] aggressively releasing JDBC connection
2013-09-25 16:22:34,177 DEBUG [org.hibernate.jdbc.ConnectionManager:464] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2013-09-25 16:22:34,178 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:297] checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,178 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,178 DEBUG [org.hibernate.engine.TwoPhaseLoad:130] resolving associations for [sii.hippoComp.server.domain.Collaborateurs#47]
2013-09-25 16:22:34,178 DEBUG [org.hibernate.loader.Loader:2022] loading entity: [sii.hippoComp.server.domain.Roles#2]
2013-09-25 16:22:34,178 DEBUG [org.hibernate.jdbc.AbstractBatcher:410] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2013-09-25 16:22:34,180 DEBUG [org.hibernate.jdbc.ConnectionManager:444] opening JDBC connection
2013-09-25 16:22:34,180 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:297] checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,180 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:554] acquire test -- pool is already maxed out. [managed: 10; max: 10]
2013-09-25 16:22:34,180 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1291] awaitAvailable(): com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb
2013-09-25 16:22:34,180 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,181 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,181 DEBUG [org.hibernate.SQL:111] select roles0_.ID as ID10_0_, roles0_.DATECREATION as DATECREA2_10_0_, roles0_.DATEMODIFICATION as DATEMODI3_10_0_, roles0_.NOM as NOM10_0_, roles0_.VERSION as VERSION10_0_ from Roles roles0_ where roles0_.ID=?
2013-09-25 16:22:34,181 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:179] com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache ----> CACHE HIT
2013-09-25 16:22:34,181 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:196] checkoutStatement: com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 1; num connections: 7; num keys: 50
2013-09-25 16:22:34,183 DEBUG [org.hibernate.jdbc.AbstractBatcher:426] about to open ResultSet (open ResultSets: 0, globally: 0)
2013-09-25 16:22:34,183 DEBUG [org.hibernate.loader.Loader:1322] result row: EntityKey[sii.hippoComp.server.domain.Roles#2]
2013-09-25 16:22:34,183 DEBUG [org.hibernate.jdbc.AbstractBatcher:433] about to close ResultSet (open ResultSets: 1, globally: 1)
2013-09-25 16:22:34,183 DEBUG [org.hibernate.jdbc.AbstractBatcher:418] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2013-09-25 16:22:34,184 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:271] checkinStatement(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,184 DEBUG [org.hibernate.jdbc.ConnectionManager:427] aggressively releasing JDBC connection
2013-09-25 16:22:34,184 DEBUG [org.hibernate.jdbc.ConnectionManager:464] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2013-09-25 16:22:34,184 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:297] checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,184 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,185 DEBUG [org.hibernate.engine.TwoPhaseLoad:130] resolving associations for [sii.hippoComp.server.domain.Roles#2]
2013-09-25 16:22:34,185 DEBUG [org.hibernate.engine.TwoPhaseLoad:255] done materializing entity [sii.hippoComp.server.domain.Roles#2]
2013-09-25 16:22:34,185 DEBUG [org.hibernate.loader.Loader:2050] done entity load
2013-09-25 16:22:34,185 DEBUG [org.hibernate.engine.TwoPhaseLoad:255] done materializing entity [sii.hippoComp.server.domain.Collaborateurs#47]
2013-09-25 16:22:34,185 DEBUG [org.hibernate.engine.StatefulPersistenceContext:893] initializing non-lazy collections
2013-09-25 16:22:34,185 DEBUG [org.hibernate.jdbc.ConnectionManager:427] aggressively releasing JDBC connection
2013-09-25 16:22:34,186 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:297] checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,186 DEBUG [sii.hippoComp.server.managerDao.GroupesNotesManager:914]  Note  	 | listHistNotes.DateDebut 	 | listHistNotes.DateFin  	 | listHistNotes.CompId  	 | listHistNotes.CollabId 
2013-09-25 16:22:34,186 DEBUG [sii.hippoComp.server.managerDao.GroupesNotesManager:914]  Note  	 | listHistNotes.DateDebut 	 | listHistNotes.DateFin  	 | listHistNotes.CompId  	 | listHistNotes.CollabId 
2013-09-25 16:22:34,186 DEBUG [sii.hippoComp.server.managerDao.GroupesNotesManager:919]   0	 | 2013-09-01 00:00:00 		 | null 			 | 67 				 | 47
2013-09-25 16:22:34,186 DEBUG [sii.hippoComp.server.managerDao.GroupesNotesManager:919]   0	 | 2013-09-01 00:00:00 		 | null 			 | 67 				 | 47
2013-09-25 16:22:34,186 DEBUG [sii.hippoComp.server.managerDao.GroupesNotesManager:914]  Note  	 | listHistNotes.DateDebut 	 | listHistNotes.DateFin  	 | listHistNotes.CompId  	 | listHistNotes.CollabId 
2013-09-25 16:22:34,186 DEBUG [sii.hippoComp.server.managerDao.GroupesNotesManager:914]  Note  	 | listHistNotes.DateDebut 	 | listHistNotes.DateFin  	 | listHistNotes.CompId  	 | listHistNotes.CollabId 
2013-09-25 16:22:34,186 DEBUG [sii.hippoComp.server.managerDao.GroupesNotesManager:919]   0	 | 2013-09-01 00:00:00 		 | null 			 | 67 				 | 47
2013-09-25 16:22:34,186 DEBUG [sii.hippoComp.server.managerDao.GroupesNotesManager:919]   0	 | 2013-09-01 00:00:00 		 | null 			 | 67 				 | 47
2013-09-25 16:22:34,186 DEBUG [sii.hippoComp.server.managerDao.GroupesNotesManager:558] Debut d'algorithme d'initialisation de la list des GROUPENOTE cas ListGN == Null et cas traitement 1 eme Collab
2013-09-25 16:22:34,186 DEBUG [sii.hippoComp.server.managerDao.GroupesNotesManager:558] Debut d'algorithme d'initialisation de la list des GROUPENOTE cas ListGN == Null et cas traitement 1 eme Collab
2013-09-25 16:22:34,186 DEBUG [org.hibernate.impl.SessionImpl:265] opened session at timestamp: 13801189541
2013-09-25 16:22:34,187 DEBUG [org.hibernate.jdbc.AbstractBatcher:410] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2013-09-25 16:22:34,187 DEBUG [org.hibernate.jdbc.ConnectionManager:444] opening JDBC connection
2013-09-25 16:22:34,187 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,187 DEBUG [org.hibernate.SQL:111] select competence0_.ID as ID3_, competence0_.DATECREATION as DATECREA2_3_, competence0_.DATEMODIFICATION as DATEMODI3_3_, competence0_.NOM as NOM3_, competence0_.THEME_ID as THEME6_3_, competence0_.VERSION as VERSION3_ from Competences competence0_ where competence0_.ID=? limit ?
2013-09-25 16:22:34,187 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:179] com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache ----> CACHE HIT
2013-09-25 16:22:34,187 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:196] checkoutStatement: com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 1; num connections: 7; num keys: 50
2013-09-25 16:22:34,189 DEBUG [org.hibernate.jdbc.AbstractBatcher:426] about to open ResultSet (open ResultSets: 0, globally: 0)
2013-09-25 16:22:34,189 DEBUG [org.hibernate.loader.Loader:1322] result row: EntityKey[sii.hippoComp.server.domain.Competences#67]
2013-09-25 16:22:34,189 DEBUG [org.hibernate.jdbc.AbstractBatcher:433] about to close ResultSet (open ResultSets: 1, globally: 1)
2013-09-25 16:22:34,190 DEBUG [org.hibernate.jdbc.AbstractBatcher:418] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2013-09-25 16:22:34,190 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:271] checkinStatement(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,190 DEBUG [org.hibernate.jdbc.ConnectionManager:427] aggressively releasing JDBC connection
2013-09-25 16:22:34,190 DEBUG [org.hibernate.jdbc.ConnectionManager:464] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2013-09-25 16:22:34,190 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:297] checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,190 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,191 DEBUG [org.hibernate.engine.TwoPhaseLoad:130] resolving associations for [sii.hippoComp.server.domain.Competences#67]
2013-09-25 16:22:34,191 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:297] checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,191 DEBUG [org.hibernate.loader.Loader:2022] loading entity: [sii.hippoComp.server.domain.Themes#14]
2013-09-25 16:22:34,191 DEBUG [org.hibernate.jdbc.AbstractBatcher:410] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2013-09-25 16:22:34,191 DEBUG [org.hibernate.jdbc.ConnectionManager:444] opening JDBC connection
2013-09-25 16:22:34,192 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,192 DEBUG [org.hibernate.SQL:111] select themes0_.ID as ID11_1_, themes0_.CATEGORIE_ID as CATEGORIE6_11_1_, themes0_.DATECREATION as DATECREA2_11_1_, themes0_.DATEMODIFICATION as DATEMODI3_11_1_, themes0_.NOM as NOM11_1_, themes0_.VERSION as VERSION11_1_, categories1_.ID as ID0_0_, categories1_.DATECREATION as DATECREA2_0_0_, categories1_.DATEMODIFICATION as DATEMODI3_0_0_, categories1_.NOM as NOM0_0_, categories1_.VERSION as VERSION0_0_ from Themes themes0_ inner join Categories categories1_ on themes0_.CATEGORIE_ID=categories1_.ID where themes0_.ID=?
2013-09-25 16:22:34,193 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:179] com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache ----> CACHE HIT
2013-09-25 16:22:34,194 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:196] checkoutStatement: com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 1; num connections: 7; num keys: 50
2013-09-25 16:22:34,196 DEBUG [org.hibernate.jdbc.AbstractBatcher:426] about to open ResultSet (open ResultSets: 0, globally: 0)
2013-09-25 16:22:34,196 DEBUG [org.hibernate.loader.Loader:1322] result row: EntityKey[sii.hippoComp.server.domain.Categories#4], EntityKey[sii.hippoComp.server.domain.Themes#14]
2013-09-25 16:22:34,196 DEBUG [org.hibernate.jdbc.AbstractBatcher:433] about to close ResultSet (open ResultSets: 1, globally: 1)
2013-09-25 16:22:34,197 DEBUG [org.hibernate.jdbc.AbstractBatcher:418] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2013-09-25 16:22:34,197 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:271] checkinStatement(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,197 DEBUG [org.hibernate.jdbc.ConnectionManager:427] aggressively releasing JDBC connection
2013-09-25 16:22:34,197 DEBUG [org.hibernate.jdbc.ConnectionManager:464] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2013-09-25 16:22:34,198 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:297] checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,198 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,198 DEBUG [org.hibernate.engine.TwoPhaseLoad:130] resolving associations for [sii.hippoComp.server.domain.Categories#4]
2013-09-25 16:22:34,198 DEBUG [org.hibernate.engine.TwoPhaseLoad:255] done materializing entity [sii.hippoComp.server.domain.Categories#4]
2013-09-25 16:22:34,198 DEBUG [org.hibernate.engine.TwoPhaseLoad:130] resolving associations for [sii.hippoComp.server.domain.Themes#14]
2013-09-25 16:22:34,198 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:297] checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,199 DEBUG [org.hibernate.engine.TwoPhaseLoad:255] done materializing entity [sii.hippoComp.server.domain.Themes#14]
2013-09-25 16:22:34,199 DEBUG [org.hibernate.loader.Loader:2050] done entity load
2013-09-25 16:22:34,199 DEBUG [org.hibernate.engine.TwoPhaseLoad:255] done materializing entity [sii.hippoComp.server.domain.Competences#67]
2013-09-25 16:22:34,200 DEBUG [org.hibernate.engine.StatefulPersistenceContext:893] initializing non-lazy collections
2013-09-25 16:22:34,200 DEBUG [org.hibernate.jdbc.ConnectionManager:427] aggressively releasing JDBC connection
2013-09-25 16:22:34,200 DEBUG [org.hibernate.impl.SessionImpl:265] opened session at timestamp: 13801189542
2013-09-25 16:22:34,200 DEBUG [org.hibernate.transaction.JDBCTransaction:78] begin
2013-09-25 16:22:34,200 DEBUG [org.hibernate.jdbc.ConnectionManager:444] opening JDBC connection
2013-09-25 16:22:34,201 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)
2013-09-25 16:22:34,201 DEBUG [org.hibernate.transaction.JDBCTransaction:83] current autocommit status: true
2013-09-25 16:22:34,201 DEBUG [org.hibernate.transaction.JDBCTransaction:86] disabling autocommit
2013-09-25 16:22:34,202 DEBUG [org.hibernate.jdbc.AbstractBatcher:410] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2013-09-25 16:22:34,202 DEBUG [org.hibernate.SQL:111] select groupescol0_.ID as ID4_, groupescol0_.DATECREATION as DATECREA2_4_, groupescol0_.DATEFIN as DATEFIN4_, groupescol0_.NOM as NOM4_, groupescol0_.VERSION as VERSION4_ from GroupesCollaborateurs groupescol0_ where groupescol0_.ID=? limit ?
2013-09-25 16:22:34,203 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:179] com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache ----> CACHE HIT
2013-09-25 16:22:34,203 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:196] checkoutStatement: com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 1; num connections: 7; num keys: 50
2013-09-25 16:22:34,204 DEBUG [org.hibernate.jdbc.AbstractBatcher:426] about to open ResultSet (open ResultSets: 0, globally: 0)
2013-09-25 16:22:34,205 DEBUG [org.hibernate.loader.Loader:1322] result row: EntityKey[sii.hippoComp.server.domain.GroupesCollaborateurs#19]
2013-09-25 16:22:34,205 DEBUG [org.hibernate.jdbc.AbstractBatcher:433] about to close ResultSet (open ResultSets: 1, globally: 1)
2013-09-25 16:22:34,205 DEBUG [org.hibernate.jdbc.AbstractBatcher:418] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2013-09-25 16:22:34,205 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache:271] checkinStatement(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 50; checked out: 0; num connections: 7; num keys: 50
2013-09-25 16:22:34,205 DEBUG [org.hibernate.engine.TwoPhaseLoad:130] resolving associations for [sii.hippoComp.server.domain.GroupesCollaborateurs#19]
2013-09-25 16:22:34,205 DEBUG [org.hibernate.engine.TwoPhaseLoad:255] done materializing entity [sii.hippoComp.server.domain.GroupesCollaborateurs#19]
2013-09-25 16:22:34,206 DEBUG [org.hibernate.engine.StatefulPersistenceContext:893] initializing non-lazy collections
2013-09-25 16:22:34,206 DEBUG [sii.hippoComp.server.managerDao.GroupesNotesManager:890]  SOMMENOTE  	 | GroupesNotes.DateDebut 	 | GroupesNotes.DateFin  | GroupesNotes.NBCOLLAB 
2013-09-25 16:22:34,206 DEBUG [sii.hippoComp.server.managerDao.GroupesNotesManager:890]  SOMMENOTE  	 | GroupesNotes.DateDebut 	 | GroupesNotes.DateFin  | GroupesNotes.NBCOLLAB 
2013-09-25 16:22:34,206 DEBUG [sii.hippoComp.server.managerDao.GroupesNotesManager:895]   0		 | 2013-09-01 00:00:00 		 | null 		 | 1
2013-09-25 16:22:34,206 DEBUG [sii.hippoComp.server.managerDao.GroupesNotesManager:895]   0		 | 2013-09-01 00:00:00 		 | null 		 | 1
2013-09-25 16:22:34,206 DEBUG [sii.hippoComp.server.managerDao.GroupesNotesManager:318] *** - collaborateurDansGroupePourUneCompetence - ***
2013-09-25 16:22:34,206 DEBUG [sii.hippoComp.server.managerDao.GroupesNotesManager:318] *** - collaborateurDansGroupePourUneCompetence - ***
2013-09-25 16:22:34,206 DEBUG [org.hibernate.jdbc.AbstractBatcher:410] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2013-09-25 16:22:34,206 DEBUG [org.hibernate.jdbc.ConnectionManager:444] opening JDBC connection
2013-09-25 16:22:34,206 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:554] acquire test -- pool is already maxed out. [managed: 10; max: 10]
2013-09-25 16:22:34,207 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1291] awaitAvailable(): com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb
2013-09-25 16:22:34,207 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool:1644] trace com.mchange.v2.resourcepool.BasicResourcePool@92c979 [managed: 10, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@f590bb)

J'ai donc le sentiment que mon entityManager me donne une nouvelle transaction dans le DAO et que malgré le commit, il ne ferme pas celle qu'il vient d'ouvrir ...
Une idée ?

Salut,

peux-tu joindre le fichier persistence.xml de test stp ?

Le fichier persistence.xml :

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
 
<?xml version="1.0" encoding="UTF-8"?>
<persistence xmlns="http://java.sun.com/xml/ns/persistence" version="1.0">
	<persistence-unit name="JPA" transaction-type="RESOURCE_LOCAL">
		<provider>org.hibernate.ejb.HibernatePersistence</provider>
 
		<!-- Nécessaire lors des tests unitaires -->
		<class>sii.hippoComp.server.domain.Categories</class>
        <class>sii.hippoComp.server.domain.CollaborateurGroupe</class>
        <class>sii.hippoComp.server.domain.Collaborateurs</class>
        <class>sii.hippoComp.server.domain.Competences</class>
        <class>sii.hippoComp.server.domain.EMF</class>
        <class>sii.hippoComp.server.domain.GroupesCollaborateurs</class>
        <class>sii.hippoComp.server.domain.GroupesNotes</class>
        <class>sii.hippoComp.server.domain.HistNotes</class>
        <class>sii.hippoComp.server.domain.Notes</class>
        <class>sii.hippoComp.server.domain.NotesPonderees</class>
        <class>sii.hippoComp.server.domain.Parametre</class>
        <class>sii.hippoComp.server.domain.Roles</class>
        <class>sii.hippoComp.server.domain.Themes</class>
 
		<properties>
			<property name="hibernate.archive.autodetection" value="class, hbm" />
			<!-- Database connection settings -->
			<property name="hibernate.connection.driver_class" value="com.mysql.jdbc.Driver" />
 
			<!-- ou basehippocomp ou hippov22_maj_modele hippov22_maj_modele -->
<!-- 			Adresse de serveur BDD local -->
<!-- 			<property name="hibernate.connection.url" value="jdbc:mysql://localhost:3306/basehippocomp" /> -->
<!-- 			Adresse de serveur BDD de RU -->
			<property name="hibernate.connection.url" value="jdbc:mysql://10.10.1.88:3306/basehippocompv33PROD" />
 
			<property name="hibernate.connection.username" value="hippocomp" />
			<property name="hibernate.connection.password" value="foobar" />
 
			<!-- JDBC connection pool (use the built-in) -->
			<property name="connection.pool_size" value="1" />
 
			<!-- SQL dialect -->
			<property name="hibernate.dialect" value="org.hibernate.dialect.MySQL5InnoDBDialect" />
 
			<!-- Enable Hibernate's automatic session context management -->
			<property name="current_session_context_class" value="thread" />
 
			<!-- Disable the second-level cache -->
			<property name="cache.provider_class" value="org.hibernate.cache.NoCacheProvider" />
 
			<!-- Echo all executed SQL to stdout -->
			<property name="hibernate.show_sql" value="false" />
			<property name="hibernate.format_sql" value="false" />
 
			<!-- Drop and re-create the database schema on startup -->
			<!-- This property should not be set in PRODUCTION environments -->
			<property name="hibernate.hbm2ddl.auto" value="update" />
 
			<property name="hibernate.c3p0.min_size" value="5" />
			<property name="hibernate.c3p0.max_size" value="10" />
			<property name="hibernate.c3p0.timeout" value="300" />
			<property name="hibernate.c3p0.max_statements" value="50" />
			<property name="hibernate.c3p0.idle_test_period" value="3000" />
		</properties>
	</persistence-unit>
</persistence>

Premièrement, parce que ce n'est pas évident vu comme c'est montré, as-tu reproduit la fuite de connection avec ton test unitaire? Si tu finis ton test, disons pas un Thread.sleep(50000); tu cnstate bien sur ton serveur DB qu'il y a n connection en plus qui restent là?

Ce qui m'inquiète aussi, c'est ça:
Code:

1 2 3 4 public static final EntityManager entityManager() { //EMF est un EntityManagerFactory en mode Singleton return EMF.get().createEntityManager(); }
ça veux dire que si t'as dans une requête, 2 appel à entityManager(), tu crée deux entitymanager. Normalement, c'est le même qu'on continue à recevoir tant qu'il n'a pas été fermé.

Enfin, si tu arrive à reproduire le problème, en production, par exemple, des outils de profilings pourraient t'aider à déterminer qui "possède" les connection en cours et où elles ont été instanciées.

C'est un peu longuet à apprendre comme outil, mais c'est très efficace pour repérer les fuites :)

Merci d'avoir pris le temps de regarder mon problème...
Oui, mon TU met bien en évidence cette fuite de mémoire (voir dernière ligne du log : [managed: 10, unused: 0, excluded: 0])

J'ai essayé quelques ajustements comme par exemple remonter l'ouverture de la transaction au niveau du point d'entrée pour n'avoir qu'une seule transaction, et j'ai l'impression qu'à chaque fois que je fais un em.persist(), il ouvre systématiquement une nouvelle transaction ... C'est assez étrange.

Et pour ta remarque sur la création d'un nouvel EntityManager via la factory, je suis d'accord, mais pour mon TU, je ne fais l'appel qu'une seule fois à cette création.

Citation:

Envoyé par bulldozer27350

Merci d'avoir pris le temps de regarder mon problème...
Oui, mon TU met bien en évidence cette fuite de mémoire (voir dernière ligne du log : [managed: 10, unused: 0, excluded: 0])

Effectivement, je n'avais pas vu que le log était sur le 10 test :)
Je vois ceci dedans:
Code:

1 2 3 2013-09-25 16:22:34,206 DEBUG [sii.hippoComp.server.managerDao.GroupesNotesManager:318] *** - collaborateurDansGroupePourUneCompetence - *** 2013-09-25 16:22:34,206 DEBUG [org.hibernate.jdbc.AbstractBatcher:410] about to open PreparedStatement (open PreparedStatements: 0, globally: 0) 2013-09-25 16:22:34,206 DEBUG [org.hibernate.jdbc.ConnectionManager:444] opening JDBC connection
Ce que je constate c'est que entre ton dernier log perso (GroupesNotesManager:318) et le crash par saturation, on demande à Hibernate de faire une opération de type batch, mais on ne lui fournis pas transaction / connection à utiliser, du coup il va se servir dans le connexion pool....

En fait ton code est plein d'endroit où l'on fait du travail "hors transaction" et que, du coup, hibernate arrête pas de redemander des connexion aux pool pour les rendre juste après. C'est pas beau mais ce n'est pas un problème en soit. Le problème, c'est que tu ouvre quelque part une transaction que tu ne ferme pas. On peux analyser la trace n° 10 pour voir à quel moment tu demande 2 transaction sans fermer la précédente, mais ce n'est probablement pas là le problème car tu peux très bien avoir avec ce meltingpot

Citation:

new connection
blabla
new connection <-- ho zut, pas possible, le pool est saturé :(
blabla
close connection
close connection

Ce qu'il faut, c'est analyser toutes les demandes de connection et leur release lors du test n°9, car c'est lui qui a fuité en dernier une connection ;)

Le mieux serait quand même que tout le code impliqué utilise la même session hibernate plutot qu'avoir chaque bout qui fait son solo et donc demande systématiquement une session. Mais vu ton explication, je crois que ca va être galère à corriger :)

tu peux commencer par faire un test avec une config simple JPA (sans cp30 )
avec juste le driver et les paramètres de connexion à la base.

Code:

1
2
3
4
5
<property name="hibernate.connection.driver_class" value="com.mysql.jdbc.Driver" />
<property name="hibernate.connection.url" value="jdbc:mysql://10.10.1.88:3306/basehippocompv33PROD" />
<property name="hibernate.connection.username" value="hippocomp" />
<property name="hibernate.connection.password" value="foobar" />
<property name="hibernate.dialect" value="org.hibernate.dialect.MySQL5InnoDBDialect" />

pour voir ce que ça donne.

ca ne fera que faire réussir son test unitaire, mais ça ne l'aidera pas à trouver où est la fuite :)

En effet, mon test unitaire passe sans le pool de connexion.
Par contre, la fuite est toujours là : sur MySQL, j'ai toujours une liste de connexions ouvertes et en attente. Elles ne se fermeront qu'au timeout défini par MySQL.

Donc ça ne corrige pas mon problème. Mais là encore, merci d'avoir pris le temps de regarder ...

son test est déja vert. mais puisque je vois pas de problème dans le code, je lui proposait une piste qui consiste à commencer par une config JPA de base qui fonctionne sans pool de connexion cp30 pour voir s'il a encore des problèmes.
Peut être que le problème vient de la pool de connexion non ?

J'aurai tendance à penser que non, puisque les connexions sont toujours ouvertes sur MySQL sans pool de connexion.

[note pour moi-même]
Alors après, je peux aussi mettre 1 million dans le nombre de connexion max, comme ça, celles qui sont ouvertes depuis trop longtemps tomberont dans le timeout, mais ça n'empêchera pas la fuite d'exister et de poser des problèmes de sécurité et de latence du SGBD ...

Ce n'est pas parce qu'on se bande les yeux qu'on peut certifier qu'il n'y a pas de problème :aie: :mouarf:
[/note pour moi même]

Citation:

Envoyé par chortani

son test est déja vert.

A ce sujet, pourrais-t-on avoir un clarification? Par le fait que le test met en évidence le fuite, je suppose que tu veux dire qu'à la 10ème insertion, comme le pool est plein, tu te choppe une exception JPA? Ou alors que le test attends quelques minutes le timeout des connections ouvertes pour continuer à avancer?

Citation:

Envoyé par chortani

puisque je vois pas de problème dans le code

En même temps il n'y a 3 fois rien comme code. So problème c'est que quelque part, surement au fin fond d'une de ses méthodes, il crée un session ou un entittymanager ou une transaction et ne la ferme jamais ;)

La question, c'est comment arriver efficacement à déterminier "Où" sans devoir lire les surement 50.000 classes que doit avoir maintenant la bête ^^

Oui, le TU passe au vert après que tout soit passé en timeout.

Pendant ce temps sur MySQL, plusieurs connexions restent ouvertes

y a t'il pas d'autre appli au moment du test qui tape sur la base mysql par hasard ?

@chortani: le probleme c'est le connection leak, généré par son test. Je pense qu'on peux être d'accord que le code appelé par le test est responsable du leak. Maintenant, le trouver..... :aie:

On peux avoir le log complet de l'item précédent du test, pour analyser les connection / release ?

Je mets le tag "Résolu".
Je suis en RTT aujourd'hui et je pars sur une autre mission demain...
Les joies de l'intercontrat ...:calim2:

Du coup, le problème n'est pas résolu, mais ce n'est plus à moi de m'en occuper ...

Merci en tout cas pour votre aide et votre patience :)

:ccool: