Différents niveaux de journalisation dans Hibernate

1. Vue d'ensemble

Puisque Hibernate gère l'interaction avec la base de données pour nous, nous sommes en mesure de développer rapidement du code lié à la base de données. Mais cela peut rendre difficile le débogage des échecs liés à la base de données.

Par conséquent, il peut être utile de visualiser l'interaction d'Hibernate avec la base de données. Par exemple, le SQL généré par Hibernate pour lire les données d'une table.

Dans ce tutoriel, nous verrons les différents niveaux de journalisation dans Hibernate qui peuvent être utilisés pour y parvenir .

2. Journalisation SQL

Au niveau le plus élémentaire, nous pouvons enregistrer les instructions SQL générées par Hibernate sans que les valeurs de paramètres réelles ne lui soient transmises.

Hibernate utilise la catégorie org.hibernate.SQL pour consigner ces informations. Donc, tout ce que nous avons à faire est de définir le niveau de journalisation de cette catégorie sur DEBUG.

Dans Log4J, nous devrons ajouter un élément logger dans le XML de configuration:

De même, dans Log4J2, nous ajouterons un élément Logger :

Et, dans Logback, nous ajouterons un élément de journalisation :

Nous devrions maintenant voir le SQL généré dans les journaux:

2019-12-07 23:04:23 | DEBUG | [main] o.h.SQL:127 - insert into Employee (employeeNumber, name, title, id) values (?, ?, ?, ?) 2019-12-07 23:04:23 | DEBUG | [main] o.h.SQL:127 - select employee0_.id as id1_0_, employee0_.employeeNumber as employee2_0_, employee0_.name as name3_0_, employee0_.title as title4_0_ from Employee employee0_

3. Valeurs des paramètres de journalisation

Bien que normalement le SQL généré soit suffisant pour identifier les problèmes, nous souhaitons parfois afficher également les paramètres passés à l'instruction SQL.

Hibernate enregistre les paramètres d'entrée et récupère les résultats à l'aide de la catégorie org.hibernate.type.descriptor.sql avec un niveau de journalisation TRACE . Maintenant, ajoutons cette catégorie à nos fichiers de configuration.

Dans Log4J, nous faisons:

Dans Log4J2:

Et enfin, dans Logback:

Par conséquent, nous devrions voir les valeurs des paramètres passées à l'instruction SQL ainsi que le résultat de l'exécution:

2019-12-07 23:04:23 | DEBUG | [main] o.h.SQL:127 - insert into Employee (employeeNumber, name, title, id) values (?, ?, ?, ?) 2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicBinder:64 - binding parameter [1] as [VARCHAR] - [001] 2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicBinder:64 - binding parameter [2] as [VARCHAR] - [John Smith] 2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicBinder:52 - binding parameter [3] as [VARCHAR] - [null] 2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicBinder:64 - binding parameter [4] as [BIGINT] - [1] 2019-12-07 23:04:23 | DEBUG | [main] o.h.SQL:127 - select employee0_.id as id1_0_, employee0_.employeeNumber as employee2_0_, employee0_.name as name3_0_, employee0_.title as title4_0_ from Employee employee0_ 2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicExtractor:60 - extracted value ([id1_0_] : [BIGINT]) - [1] 2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicExtractor:60 - extracted value ([employee2_0_] : [VARCHAR]) - [001] 2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicExtractor:60 - extracted value ([name3_0_] : [VARCHAR]) - [John Smith] 2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicExtractor:50 - extracted value ([title4_0_] : [VARCHAR]) - [null]

Il est à noter que nous n'avons pas besoin d'activer la catégorie org.hibernate.SQL pour afficher les informations ci-dessus. Nous pouvons activer et désactiver les deux catégories indépendamment .

Mais, il est logique d'activer org.hibernate.SQL afin que nous sachions à quelle instruction SQL les valeurs de paramètre se rapportent .

4. Activer les statistiques Hibernate

Outre les valeurs des paramètres SQL et JDBC, Hibernate peut également enregistrer des statistiques pour chaque instruction SQL. Cela peut être utile pour identifier les problèmes de performances potentiels.

Hibernate utilise la catégorie org.hibernate.stat pour consigner ces informations. Mais, Hibernate ne génère pas toujours ces statistiques car cela peut avoir une mauvaise influence sur les performances.

Tout d'abord, nous devons dire à Hibernate de générer ces statistiques en définissant la propriété de configuration hibernate.generate_statistics sur true .

Par exemple, nous pouvons définir cette propriété dans notre fichier hibernate.cfg.xml :

true

Parallèlement à cette propriété, définir la catégorie org.hibernate.stat sur DEBUG enregistrera une instruction avec les statistiques de chaque requête exécutée . Il enregistrera également une instruction de journal multiligne à la fin de la session qui aura résumé les informations statistiques:

2019-12-07 23:25:18 | DEBUG | [main] o.h.s.i.StatisticsInitiator:101 - Statistics initialized [enabled=true] 2019-12-07 23:25:19 | DEBUG | [main] o.h.s.i.StatisticsImpl:729 - HHH000117: HQL: from com.baeldung.hibernate.logging.Employee, time: 22ms, rows: 1 2019-12-07 23:25:19 | INFO | [main] o.h.e.i.StatisticalLoggingSessionEventListener:258 - Session Metrics { 55600 nanoseconds spent acquiring 1 JDBC connections; 178600 nanoseconds spent releasing 1 JDBC connections; 2167200 nanoseconds spent preparing 2 JDBC statements; 2426800 nanoseconds spent executing 2 JDBC statements; 0 nanoseconds spent executing 0 JDBC batches; 0 nanoseconds spent performing 0 L2C puts; 0 nanoseconds spent performing 0 L2C hits; 0 nanoseconds spent performing 0 L2C misses; 47098900 nanoseconds spent executing 1 flushes (flushing a total of 1 entities and 0 collections); 0 nanoseconds spent executing 0 partial-flushes (flushing a total of 0 entities and 0 collections) }

Notez la première ligne du journal qui indique que les statistiques sont activées.

5. Consigner toutes les activités

Pour approfondir encore davantage l'interaction d'Hibernate avec la base de données, nous devrons activer la journalisation pour la catégorie org.hibernate . Cette catégorie contient tous les messages enregistrés par Hibernate.

Mais, nous devons utiliser cette catégorie avec prudence car elle pourrait créer beaucoup de sortie de journal:

6. Conclusion

Dans ce tutoriel, nous avons vu les différents niveaux de journalisation dans Hibernate. Les informations enregistrées peuvent être très utiles lors du développement. Mais nous devons être prudents lors de l'activation de cela en production car cela peut nuire aux performances de l'application.

Et bien sûr, le code qui accompagne ce tutoriel peut être trouvé sur GitHub.