Una base de datos relacional guarda los datos de forma diferente al modelo orientado a objetos que utilizamos en lenguajes como Java, C# o Python. Los ORM (Object-relational mapping) tratan de hacer una correspondencia entre los dos modelos, el relacional de las bases de datos y el orientado a objetos de los lenguajes. Una de las ventajas de usar en una aplicación un ORM para acceder a la base de datos es que podemos hacer una correspondencia entre los datos de una base de datos relacional y trabajar con esos datos utilizando el modelo orientado a objetos del lenguaje de programación que usemos.
Sin embargo, el ORM envía sentencias SQL para recuperar los datos de la base de datos relacional según vamos navegando con los métodos de acceso a otros objetos y sus relaciones. Depende de como el ORM haga las consultas para recuperar los datos de la base de datos relacional puede generar muchas SQL, producir un bajo rendimiento en la aplicación y una carga de trabajo considerable para la base de datos.
En los ORM es conocido el problema N+1. Consiste en lo siguiente, supongamos que tenemos dos tablas relacionadas autores y libros, y que la relación entre estas dos tablas es de 1 a N, de modo que un autor puede tener varios libros y un libro ha sido escrito por un único autor. Para recuperar todos los autores necesitaríamos una consulta y si no hacemos una join con la tabla de libros para recuperar los libros de cada autor tendríamos que hacer otra consulta con lo que tendríamos el problema N+1 al hacer un bucle sobre los autores (1 consulta para los autores y N para los libros de cada autor).
El problema está en que el ORM lanza las consultas de forma automática según necesita los datos de modo que si para un autor no tiene los libros lanza una SQL para recuperarlos, como programadores llamar a un método para acceder a los libros es muy cómodo y transparente para nosotros (trabajamos solo con objetos) pero hemos de ser conscientes de las consultas que lanza el ORM porque podemos producir una situación de N+1.
Para evitar el problema N+1 hemos de recuperar todos los datos haciendo una única consulta, haciendo una join entre las tablas autor y libro. En Hibernate podemos resolverlo con una consulta HQL como la siguiente:
1
2
|
"from Autor as autor left outer join autor.libros as libro"
|
hql.txt
O con una criteria en Grails:
1
2
|
Criteria criteria = session.createCriteria(Autor.class);
criteria.setFetchMode("libros", FetchMode.EAGER);
|
Criteria.groovy
Pero para saber en que sitios de nuestro código debemos establecer los métodos de búsqueda EAGER necesitamos detectar los problemas N+1, con la experiencia conoceremos donde se pueden producir, otros casos se nos pueden pasar por alto y necesitaremos detectarlos. Para detectar estos problemas N+1 o para determinar si una página es muy lenta porque hace muchas consultas a la base de datos Hibernate dispone de unas estadísticas mediante las cuales podemos conocer cuantas consultas select, update, insert, conexiones, y más datos por entidad y relación… se han lanzado por haber accedido a una página. Podemos acceder a las estadísticas de Hibernate mediante el objeto SessionFactory y el método getStatistics, con ese objeto y método podemos obtener estadísticas globales y para cada una de las entidades persistidas por Hibernate.
En Grails podemos hacer un controlador y gsp que nos muestre esa información que podrían ser de la siguiente forma:
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
|
package io.github.picodotdev.grails.controllers
import javax.servlet.http.HttpServletResponse
import grails.converters.JSON
import grails.util.Environment
import io.github.picodotdev.grails.domain.Autor
import io.github.picodotdev.grails.log.HibernateLogger
class HibernateController {
def sessionFactory
def doTest() {
def autor = new Autor(nombre:'picodotdev')
autor.save()
autor = Autor.get(autor.id)
autor.delete()
return redirect(action:'index')
}
def index() {
def e = test()
if (!e) {
return response.sendError(HttpServletResponse.SC_FORBIDDEN)
}
def model = [estadisticas:sessionFactory.statistics]
return render(view:'/hibernate/index', model:model)
}
def enableStatistics() {
def e = test()
if (!e) {
return response.sendError(HttpServletResponse.SC_FORBIDDEN)
}
// Habilitar estadístics
sessionFactory.statistics.setStatisticsEnabled(true)
redirect(action:'index')
}
def disableStatistics() {
def e = test()
if (!e) {
return response.sendError(HttpServletResponse.SC_FORBIDDEN)
}
// Deshabilitar estadísticas
sessionFactory.statistics.setStatisticsEnabled(false)
redirect(action:'index')
}
def clearEstadisticas() {
def e = test()
if (!e) {
return response.sendError(HttpServletResponse.SC_FORBIDDEN)
}
sessionFactory.statistics.clear()
redirect(action:'index')
}
def clearMensajesHibernate() {
def e = test()
if (!e) {
return response.sendError(HttpServletResponse.SC_FORBIDDEN)
}
HibernateLogger.clear()
redirect(action:'index')
}
def logSummary() {
def e = test()
if (!e) {
return response.sendError(HttpServletResponse.SC_FORBIDDEN)
}
sessionFactory.statistics.logSummary()
redirect(action:'index')
}
private boolean test() {
if (Environment.current != Environment.DEVELOPMENT) {
return false
}
return true
}
}
|
HibernateController.groovy
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
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
|
<%@ page import="java.text.SimpleDateFormat" %>
<%@ page import="io.github.picodotdev.grails.log.HibernateLogger" %>
<%
SimpleDateFormat sdf = new SimpleDateFormat("dd/MM/yyyy HH:mm:ss Z")
%>
<!DOCTYPE html>
<html>
<head>
<title>Estadísticas de Hibernate</title>
<script src="//cdnjs.cloudflare.com/ajax/libs/jquery/2.1.1/jquery.min.js" type="text/javascript"></script>
<link href="//netdna.bootstrapcdn.com/bootstrap/3.1.1/css/bootstrap.min.css" rel="stylesheet"/>
</head>
<body>
<g:set var="o" value="${null}" />
<div class="container-fluid">
<h1>Estadísticas de Hibernate</h1>
<g:if test="${estadisticas.statisticsEnabled}">
<g:link action="disableStatistics" class="btn btn-primary">Deshabilitar estadísticas</g:link>
</g:if>
<g:else>
<g:link action="enableStatistics" class="btn btn-primary">Habilitar estadísticas</g:link>
</g:else>
<g:if test="${estadisticas.statisticsEnabled}">
<g:link action="clearEstadisticas" class="btn btn-primary">Reiniciarlizar estadísticas</g:link>
</g:if>
<g:link action="clearMensajesHibernate" class="btn btn-primary">Reiniciarlizar mensajes de Hibernate</g:link>
<g:link action="logSummary" class="btn btn-primary">Informe resumen</g:link>
<h2>Estadísticas</h2>
<g:if test="${!estadisticas.statisticsEnabled}">
Las estadísticas de Hibernate no están habilitadas.
</g:if>
<g:else>
<div class="row">
<div class="col-md-4">
<h3>Conexiones, sesiones y transacciones</h3>
<ul class="list-group">
<li class="list-group-item">StartTime <span class="badge">${sdf.format(new Date(estadisticas.startTime))}</span></li>
<li class="list-group-item" title="Get the global number of connections asked by the sessions (the actual number of connections used may be much smaller depending whether you use a connection pool or not)">ConnectCount <span class="badge">${estadisticas.connectCount}</span></li>
<li class="list-group-item" title="The number of prepared statements that were released">CloseStatementCount <span class="badge">${estadisticas.closeStatementCount}</span></li>
<li class="list-group-item" title="Global number of sessions opened">SessionOpenCount <span class="badge">${estadisticas.sessionOpenCount}</span></li>
<li class="list-group-item" title="Global number of sessions closed">SessionCloseCount <span class="badge">${estadisticas.sessionCloseCount}</span></li>
<li class="list-group-item" title="The number of transactions we know to have been successful">SuccessfulTransactionCount <span class="badge">${estadisticas.successfulTransactionCount}</span></li>
<li class="list-group-item" title="The number of transactions we know to have completed">TransactionCount <span class="badge">${estadisticas.transactionCount}</span></li>
</ul>
</div>
<div class="col-md-4">
<h3>Sentencias</h3>
<ul class="list-group">
<li class="list-group-item" title="Get global number of executed queries">QueryExecutionCount <span class="badge">${estadisticas.queryExecutionCount}</span></li>
<li class="list-group-item" title="The number of prepared statements that were acquired">PrepareStatementCount <span class="badge">${estadisticas.prepareStatementCount}</span></li>
<li class="list-group-item" title="Get all executed query strings">Queries: ${estadisticas.queries.join(', ')}</li>
<li class="list-group-item" title="Get the query string for the slowest query">QueryExecutionMaxTimeQueryString <span class="badge">${estadisticas.queryExecutionMaxTimeQueryString}</span></li>
</ul>
</div>
<div class="col-md-4">
<h3>Entidades</h3>
<ul class="list-group">
<li class="list-group-item" title="Get global number of entity fetchs">EntityFetchCount <span class="badge">${estadisticas.entityFetchCount}</span></li>
<li class="list-group-item" title="Get global number of entity loads">EntityLoadCount <span class="badge">${estadisticas.entityLoadCount}</span></li>
<li class="list-group-item" title="Get global number of entity inserts">EntityInsertCount <span class="badge">${estadisticas.entityInsertCount}</span></li>
<li class="list-group-item" title="Get global number of entity updates">EntityUpdateCount <span class="badge">${estadisticas.entityUpdateCount}</span></li>
<li class="list-group-item" title="Get global number of entity deletes">EntityDeleteCount <span class="badge">${estadisticas.entityDeleteCount}</span></li>
</ul>
</div>
</div>
<div class="row">
<div class="col-md-4">
<h3>Colecciones</h3>
<ul class="list-group">
<li class="list-group-item" title="Global number of collections fetched">CollectionFetchCount <span class="badge">${estadisticas.collectionFetchCount}</span></li>
<li class="list-group-item" title="Global number of collections loaded">CollectionLoadCount <span class="badge">${estadisticas.collectionLoadCount}</span></li>
<li class="list-group-item" title="Global number of collections recreated">CollectionRecreateCount <span class="badge">${estadisticas.collectionRecreateCount}</span></li>
<li class="list-group-item" title="Global number of collections updated">CollectionUpdateCount <span class="badge">${estadisticas.collectionUpdateCount}</span></li>
<li class="list-group-item" title="Global number of collections removed">CollectionRemoveCount <span class="badge">${estadisticas.collectionRemoveCount}</span></li>
</ul>
</div>
<div class="row">
<div class="col-md-4">
<h3>Cache</h3>
<ul class="list-group">
<li class="list-group-item" title="Get the global number of flush executed by sessions (either implicit or explicit)">FlushCount <span class="badge">${estadisticas.flushCount}</span></li>
<li class="list-group-item" title="The number of StaleObjectStateExceptions that occurred">OptimisticFailureCount <span class="badge">${estadisticas.optimisticFailureCount}</span></li>
<li class="list-group-item" title="Get the global number of cached queries successfully retrieved from cache">QueryCacheHitCount <span class="badge">${estadisticas.queryCacheHitCount}</span></li>
<li class="list-group-item" title="Get the global number of cached queries *not* found in cache">QueryCacheMissCount <span class="badge">${estadisticas.queryCacheMissCount}</span></li>
<li class="list-group-item" title="Get the global number of cacheable queries put in cache">QueryCachePutCount <span class="badge">${estadisticas.queryCachePutCount}</span></li>
<li class="list-group-item" title="Get the time in milliseconds of the slowest query">QueryExecutionMaxTime <span class="badge">${estadisticas.queryExecutionMaxTime}</span></li>
<li class="list-group-item" title="Global number of cacheable entities/collections successfully retrieved from the cache">SecondLevelCacheHitCount <span class="badge">${estadisticas.secondLevelCacheHitCount}</span></li>
<li class="list-group-item" title="Global number of cacheable entities/collections not found in the cache and loaded from the database">SecondLevelCacheMissCount <span class="badge">${estadisticas.secondLevelCacheMissCount}</span></li>
<li class="list-group-item" title="Global number of cacheable entities/collections put in the cache">SecondLevelCachePutCount <span class="badge">${estadisticas.secondLevelCachePutCount}</span></li>
</ul>
</div>
</div>
</div>
<h3>Detalles entidades</h3>
<div class="row">
<div class="col-md-12">
<% o = estadisticas.entityNames.sort() %>
<g:each in="${o}" var="n" status="i">
<g:set var="entityStatistics" value="${estadisticas.getEntityStatistics(n)}" />
<g:if test="${(i % 3) == 0}">
<div class="row">
</g:if>
<div class="col-md-4">
<ul class="list-group">
<li class="list-group-item"><b>${n}</b></li>
<li class="list-group-item">DeleteCount <span class="badge">${entityStatistics.deleteCount}</span></li>
<li class="list-group-item">FetchCount <span class="badge">${entityStatistics.fetchCount}</span></li>
<li class="list-group-item">InsertCount <span class="badge">${entityStatistics.insertCount}</span></li>
<li class="list-group-item">LoadCount <span class="badge">${entityStatistics.loadCount}</span></li>
<li class="list-group-item">OptimisticFailureCount <span class="badge">${entityStatistics.optimisticFailureCount}</span></li>
<li class="list-group-item">UpdateCount <span class="badge">${entityStatistics.updateCount}</span></li>
</ul>
</div>
<g:if test="${(i % 3) == 2 || o.length == (i + 1) }">
</div>
</g:if>
</g:each>
</div>
</div>
<h3>Detalles colecciones</h3>
<div class="row">
<div class="col-md-12">
<% o = estadisticas.collectionRoleNames.sort() %>
<g:each in="${o}" var="n" status="i">
<g:set var="collectionStatistics" value="${estadisticas.getCollectionStatistics(n)}" />
<g:if test="${(i % 3) == 0}">
<div class="row">
</g:if>
<div class="col-md-4">
<ul class="list-group">
<li class="list-group-item"><b>${n}</b></li>
<li class="list-group-item">FetchCount <span class="badge">${collectionStatistics.fetchCount}</span></li>
<li class="list-group-item">LoadCount <span class="badge">${collectionStatistics.loadCount}</span></li>
<li class="list-group-item">RecreateCount <span class="badge">${collectionStatistics.recreateCount}</span></li>
<li class="list-group-item">RemoveCount <span class="badge">${collectionStatistics.removeCount}</span></li>
<li class="list-group-item">UpdateCount <span class="badge">${collectionStatistics.updateCount}</span></li>
</ul>
</div>
<g:if test="${(i % 3) == 2 || o.length == (i + 1) }">
</div>
</g:if>
</g:each>
</div>
</div>
<h3>Detalles cache segundo nivel</h3>
<div class="row">
<div class="col-md-12">
<% o = estadisticas.secondLevelCacheRegionNames.sort() %>
<g:each in="${o}" var="n" status="i">
<g:set var="secondLevelCacheStatistics" value="${estadisticas.getSecondLevelCacheStatistics(n)}" />
<g:if test="${(i % 3) == 0}">
<div class="row">
</g:if>
<g:if test="${secondLevelCacheStatistics}">
<ul>
<li class="list-group-item"><b>${n}</b></li>
<li class="list-group-item">ElementCountInMemory <span class="badge">${secondLevelCacheStatistics.elementCountInMemory}</span></li>
<li>ElementCountOnDisk <span class="badge">${secondLevelCacheStatistics.elementCountOnDisk}</span></li>
<li>Entries <span class="badge">${secondLevelCacheStatistics.entries}</span></li>
<li>HitCount <span class="badge">${secondLevelCacheStatistics.hitCount}</span></li>
<li>MissCount <span class="badge">${secondLevelCacheStatistics.missCount}</span></li>
<li>PutCount <span class="badge">${secondLevelCacheStatistics.putCount}</span></li>
<li>izeInMemory <span class="badge">${secondLevelCacheStatistics.sizeInMemory}</span></li>
</ul>
</g:if>
<g:if test="${(i % 3) == 2 || o.length == (i + 1) }">
</div>
</g:if>
</g:each>
</div>
</div>
</g:else>
<h3>Mensajes de Hibernate</h3>
<div class="btn-group">
<button id="hql" type="button" class="btn btn-default active">HQL (${HibernateLogger.get().findAll({ it.type == HibernateLogger.Type.HQL }).size()})</button>
<button id="param" type="button" class="btn btn-default active">PARAM (${HibernateLogger.get().findAll({ it.type == HibernateLogger.Type.PARAM }).size()})</button>
<button id="sql" type="button" class="btn btn-default active">SQL (${HibernateLogger.get().findAll({ it.type == HibernateLogger.Type.SQL }).size()})</button>
<button id="exception" type="button" class="btn btn-default active">EXCEPTION (${HibernateLogger.get().findAll({ it.type == HibernateLogger.Type.EXCEPTION }).size()})</button>
<button id="text" type="button" class="btn btn-default active">TEXT (${HibernateLogger.get().findAll({ it.type == HibernateLogger.Type.TEXT }).size()})</button>
</div>
<div class="row">
<div class="col-md-12">
<%
o = HibernateLogger.get()
%>
<table id="logs" class="table table-striped">
<tr>
<th class="col-md-2">Fecha</th>
<th>Tipo</th>
<th>Tiempo</th>
<th>Mensaje</th>
</tr>
<g:each in="${o}" var="n" status="i">
<g:if test="${(n.type == HibernateLogger.Type.HQL && n.hql) || (n.type == HibernateLogger.Type.PARAM && n.param) || ((n.type == HibernateLogger.Type.SQL) && n.prepared && n.sql) || ((n.type == HibernateLogger.Type.EXCEPTION) && n.exception.messsage) || ((n.type == HibernateLogger.Type.TEXT) && n.text)}">
<tr class="${n.type}">
<td>${sdf.format(n.date)}</td>
<td>${n.type}</td>
<g:if test="${n.type == HibernateLogger.Type.HQL && n.hql}">
<td></td>
<td>${n.hql}</td>
</g:if>
<g:if test="${n.type == HibernateLogger.Type.PARAM && n.param}">
<td></td>
<td>${n.param}</td>
</g:if>
<g:if test="${n.type == HibernateLogger.Type.SQL && n.prepared && n.sql}">
<td>${(n.elapsed > 0)?n.elapsed:''}</td>
<td>${n.prepared}<br/><br/>${n.sql}</td>
</g:if>
<g:if test="${n.type == HibernateLogger.Type.EXCEPTION && n.exception.messsage}">
<td colspan="2">${n.exception.messsage}</th>
</g:if>
<g:if test="${n.type == HibernateLogger.Type.TEXT && n.text}">
<td colspan="2">${n.text}</th>
</g:if>
</tr>
</g:if>
</g:each>
</table>
</div>
</div>
</div>
<r:script>
$(document).ready(function() {
$('#hql').click(function() {
$(this).toggleClass('active');
var b = $(this).hasClass('active');
if (b) {
$('#logs tr.HQL').show();
} else {
$('#logs tr.HQL').hide();
}
});
$('#param').click(function() {
$(this).toggleClass('active');
var b = $(this).hasClass('active');
if (b) {
$('#logs tr.PARAM').show();
} else {
$('#logs tr.PARAM').hide();
}
});
$('#sql').click(function() {
$(this).toggleClass('active');
var b = $(this).hasClass('active');
if (b) {
$('#logs tr.SQL').show();
} else {
$('#logs tr.SQL').hide();
}
});
$('#exception').click(function() {
$(this).toggleClass('active');
var b = $(this).hasClass('active');
if (b) {
$('#logs tr.EXCEPTION').show();
} else {
$('#logs tr.EXCEPTION').hide();
}
});
$('#text').click(function() {
$(this).toggleClass('active');
var b = $(this).hasClass('active');
if (b) {
$('#logs tr.TEXT').show();
} else {
$('#logs tr.TEXT').hide();
}
});
});
</r:script>
</body>
</html>
|
index.gsp
Si además queremos ver las consultas HQL de Hibernate y parámetros que se están lanzando en cada acceso a una página podemos modificar el archivo Config.goovy y añadir la siguiente configuración en el apartado Log4j:
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
|
// log4j configuration
log4j = {
// Example of changing the log pattern for the default console appender:
//
//appenders {
// console name:'stdout', layout:pattern(conversionPattern: '%c{2} %m%n')
//}
appenders {
environments {
development {
appender new io.github.picodotdev.grails.log.HibernateAppender(name:'hibernate')
}
}
}
environments {
development {
debug additivity: false, hibernate:['org.hibernate.SQL']
trace additivity: false, hibernate:['org.hibernate.type.descriptor.sql.BasicBinder']
}
}
error 'org.codehaus.groovy.grails.web.servlet', // controllers
'org.codehaus.groovy.grails.web.pages', // GSP
'org.codehaus.groovy.grails.web.sitemesh', // layouts
'org.codehaus.groovy.grails.web.mapping.filter', // URL mapping
'org.codehaus.groovy.grails.web.mapping', // URL mapping
'org.codehaus.groovy.grails.commons', // core / classloading
'org.codehaus.groovy.grails.plugins', // plugins
'org.codehaus.groovy.grails.orm.hibernate', // hibernate integration
'org.springframework',
'org.hibernate',
'net.sf.ehcache.hibernate'
}
|
Config.groovy
La implementación de appender para capturar las HQL que lanza grails es la siguiente:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
|
package io.github.picodotdev.grails.log;
import org.apache.log4j.AppenderSkeleton;
import org.apache.log4j.spi.LoggingEvent;
public class HibernateAppender extends AppenderSkeleton {
public void append(LoggingEvent event) {
if (event.getLoggerName().equals("org.hibernate.SQL")) {
HibernateLogger.getInstance().logHQL(event.getRenderedMessage());
} else if (event.getLoggerName().equals("org.hibernate.type.descriptor.sql.BasicBinder")) {
HibernateLogger.getInstance().logParam(event.getRenderedMessage());
}
}
public boolean requiresLayout() {
return false;
}
public void close() {
}
}
|
HibernateAppender.java
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
|
package io.github.picodotdev.grails.log;
import java.util.Date;
import java.util.LinkedList;
import java.util.List;
import java.util.Map;
import java.util.HashMap;
public class HibernateLogger {
private static int MAX_LOGS = 1000;
private static LinkedList logs = new LinkedList();
private static HibernateLogger instance;
public enum Type {
HQL, PARAM, SQL, EXCEPTION, TEXT
}
public static HibernateLogger getInstance() {
if (instance == null) {
instance = new HibernateLogger();
}
return instance;
}
public void logHQL(String hql) {
Map m = new HashMap();
m.put("type", Type.HQL);
m.put("date", new Date());
m.put("hql", hql);
add(m);
}
public void logParam(String param) {
Map m = new HashMap();
m.put("type", Type.PARAM);
m.put("date", new Date());
m.put("param", param);
add(m);
}
public void logSQL(int connectionId, String now, long elapsed, String category, String prepared, String sql) {
Map m = new HashMap();
m.put("type", Type.SQL);
m.put("date", new Date());
m.put("connectionId", connectionId);
m.put("now", now);
m.put("elapsed", elapsed);
m.put("category", category);
m.put("prepared", prepared);
m.put("sql", sql);
add(m);
}
public void logException(Exception exception) {
Map m = new HashMap();
m.put("type", Type.EXCEPTION);
m.put("date", new Date());
m.put("exception", exception);
add(m);
}
public void logText(String text) {
Map m = new HashMap();
m.put("type", Type.TEXT);
m.put("date", new Date());
m.put("text", text);
add(m);
}
public String getLastEntry() {
return "";
}
public static List get() {
return logs;
}
public static void clear() {
logs.clear();
}
private static synchronized void add(Map m) {
logs.addFirst(m);
if (logs.size() > MAX_LOGS) {
logs.removeLast();
}
}
}
|
HibernateLogger.java
El resultado es el siguiente:
En la imagen se puede apreciar las consultas lanzadas y que parámetros se han empleado. El método doTest del controlador HibernateController cada vez que es ejecutado persiste una entidad de dominio Autor y posteriormente la borra lanzando una sentencia insert y otra delete, cada vez que es ejecutado las estadísticas cambian acordemente.
Obtener información de lo que sucede en la aplicación es importante y el framework debería ayudar, también podemos mejorar lo que ofrece Grails con una página de excepción más informativa. En Tapestry es más sencillo aún ya que incluyendo la dependencia de tapestry-hibernate ya se añade a la página Dashboard y un apartado con estas estadísticas, pero esto último será tema para otro artículo.
Referencia:
- Página de excepción de Grails
- https://stackoverflow.com/questions/11621495/how-can-i-obtain-grails-hibernate-l2-cache-statistics
- https://stackoverflow.com/questions/2568507/how-to-log-sql-statements-in-grails
- https://hibernate.atlassian.net/browse/HHH-3659
