JPA - Tracer les requêtes SQL avec Log4jdbc

L’utilisation de frameworks de persistance tels qu’ Hibernate, EclipseLink, TopLink ou OpenJPA permet de masquer toute la plomberie SQL et JDBC. Au point qu’on en oublierait presque qu’on travaille avec une base de données relationnelle.

Mais il y a toujours un moment où la réalité nous rattrape et où il devient indispensable de comprendre ce qui se passe de l’autre côté du décor. C'est à ce moment que le développeur s’interroge :  que fait concrètement notre framework de persistance ? Qu’est-ce qu’il nous cache ?

Bref, quelles sont les requêtes SQL envoyées à la base de données et à quel moment sont elles envoyées ?

Une première solution consiste à activer les traces du framework lui-même.

Par exemple avec JPA au niveau du fichier « persistence.xml » il suffit d’ajouter quelques propriétés de configuration.

Exemple pour  Hibernate :

Exemple pour EclipseLink :

Mais avec ce principe nous n’obtiendrons que ce que chaque framework veut bien nous donner. La configuration est propre à chaque environnement et le format des traces ne correspond pas forcément à ce que l’on souhaiterait.
Il s’agit donc d’une première réponse à la problématique des traces SQL, mais qui dans la plupart des cas se révélera insuffisante.

Ce serait tellement plus simple si on pouvait se situer entre le framework et la base de données pour voir passer les requêtes …  Et c’est là que les outils du type « proxy de driver JDBC » vont nous aider.

Avec un nom pareil on se doute bien du principe de fonctionnement …

Sans « proxy »

 

Avec « proxy »

Donc, on va « brancher » notre ORM sur un driver JDBC qui n’en est pas vraiment un. Cet usurpateur va être sollicité pour traiter les requêtes SQL qu’il va tracer, puis déléguer au « vrai » driver JDBC.

Il s’agit donc d’un « passe-plats » traceur.

Il existe différents outils de ce type, le plus connu étant certainement « P6Spy », célèbre espion au service de nos applications mais qui, contrairement à James Bond, a un peu vieilli (pas d’évolutions depuis plusieurs années).

Voici une liste (non exhaustive) de ce type d’outil :

• P6Spy  http://sourceforge.net/projects/p6spy/ 
• Log4JDBC  http://code.google.com/p/log4jdbc/ 
• Jdbcdslog  http://code.google.com/p/jdbcdslog/
• JdbcProxy  http://sourceforge.net/projects/jdbcproxy/
• SqlRecorder https://github.com/gokulesh/SqlRecorder

Voyons maintenant comment utiliser Log4JDBC…

Pourquoi lui ? Parce qu’il est à jour (JDBC 4, JDK 1.6 et 1.7) et simple à installer (et pour P6Spy il y a déjà pas mal de doc en français sur la toile).

Architecture de Log4JDBC :

Log4JDBC permet d’utiliser différents types de loggers. Pour ce faire il s’appuie sur SLF4J : « Simple Logging Facade for Java » (http://www.slf4j.org/) une couche d’abstraction qui permet de s’isoler du logger concret qui sera utilisé (Log4J, java.util.logging, logback, etc… )
Dans le cas présent nous utiliserons Log4J (les classiques ça a du bon)

1) Récupérer les JAR nécessaires

• Log4JDBC lui-même ( 1 jar : log4jdbc4-x.x.jar )
  http://code.google.com/p/log4jdbc/downloads/list 
  ( choisir le JAR correspondant à la version de JDBC utilisée )

• SLF4J  ( 2 jars :  slf4j-api-x.x.x.jar  et  slf4j-log4j12-x.x.x.jar )
  http://www.slf4j.org/ :  Download  ( version 1.5 ou plus => prendre la dernière version )

• Log4J ( 1 jar )
  http://logging.apache.org/log4j/

On doit finalement avoir  4 JARs :

Il n’a plus qu’à ajouter ces JARs au projet, par exemple sous la forme d’une User Library sous Eclipse.

2) Insérer le « proxy » entre l’ORM et le « vrai driver JDBC »

2.1 ) Brancher Log4JDBC sur le « vrai driver JDBC »

Par défaut Log4JDBC cherche à utiliser les classes des drivers JDBC les plus courants

• oracle.jdbc.OracleDriver ou oracle.jdbc.driver.OracleDriver pour Oracle
• com.mysql.jdbc.Driver pour MySQL
• org.postgresql.Driver pour PostgreSQL
• etc…

Il connait une quinzaine de drivers classiques (voir la liste complète sur http://code.google.com/p/log4jdbc/ ). Pour ceux-là il n’y a donc aucune configuration à réaliser (il va trouver tout seul la classe du driver).

Si le driver JDBC n’est pas connu, il suffit de l’indiquer avec une « system property » :
     -Dlog4jdbc.drivers=<driverclass>[,<driverclass>...]

2.2 ) Brancher l’ORM sur le « faux driver » (Log4JDBC )

La classe qui simule de driver JDBC est « net.sf.log4jdbc.DriverSpy »
Il suffit donc de l’utiliser dans la configuration de l’ORM
Exemple dans « persistence.xml »

3) Configurer les loggers

Log4JDBC dispose de 5 loggers qui pourront être activés ou non en fonction des besoins :

• jdbc.sqlonly    : trace uniquement le  SQL
• jdbc.sqltiming  : trace le SQL et les statistiques de temps (durée d’exécution d’une requête SQL)
• jdbc.audit      : trace tous les appels JDBC sauf pour les ResultSets
• jdbc.resultset  : trace tous les appels aux objets ResultSet
• jdbc.connection : trace les événements sur les connexions (open/close) et le nombre de connections ouvertes (utile pour identifier les « fuites » de connexions).

Il suffit de configurer au moins l’un de ces loggers dans le fichier « log4j.xml » pour voir les premières traces SQL.
Les loggers sont activés s’ils ont un des niveaux de trace  ERROR,  INFO  ou  DEBUG

Exemple de configuration Log4J :

4) Tester

Exemple de trace avec Hibernate :


Exemple de trace avec EclipseLink :


La configuration Log4J permet ensuite d’adapter le logger aux besoins (formatage des traces, nouveaux « appenders », etc… )