Wrong numbers of log entries in N-N relations.

rocket · **Posted:** Tue Jun 22, 2004 5:22 pm

>Hibernate 2.11 + JBoss 3.2.3 + Postgres 7.4
Hi all,
I have an N-N relation (with inverse collections and "save-update" in both directions) between "Grupo" (an group) and "Integrante" (an integrant that can be a a user or other group). This is resolved with a "GrupoIntegrante" table in a relational database.
So, using this code:

Code:

      /* 2 groups */
      Grupo g1 = new Grupo("G1");
      Grupo g2 = new Grupo("G2");
      
      /* 4 users */
      Usuario u1 = new Usuario("U1.1");
      Usuario u2 = new Usuario("U1.2");
      Usuario u3 = new Usuario("U1.2");
      Usuario u4 = new Usuario("U2.1");
      
      /* 5 links between groups and users or groups and other groups */
      g1.add(u1);
      g1.add(u2);
      g1.add(u3);
      g2.add(u4);
      g2.add(g1);
      
      gu.saveOrUpdate(g2); //gu is a Session Facade EJB

The Hibernate log show it:

Code:

49:21,965 INFO  [STDOUT] Hibernate: select nextval ('hibernate_sequence')
49:22,027 INFO  [STDOUT] Hibernate: select nextval ('hibernate_sequence')
49:22,027 INFO  [STDOUT] Hibernate: select nextval ('hibernate_sequence')
49:22,027 INFO  [STDOUT] Hibernate: select nextval ('hibernate_sequence')
49:22,027 INFO  [STDOUT] Hibernate: select nextval ('hibernate_sequence')
49:22,043 INFO  [STDOUT] Hibernate: select nextval ('hibernate_sequence')
49:22,043 INFO  [STDOUT] Hibernate: insert into Integrante (descricao, nome, email, operadorInclusao, dataHoraInclusao, operadorAlteracao, dataHoraAlteracao, versaoRegistro, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?)
49:22,043 INFO  [STDOUT] Hibernate: insert into Grupo (id) values (?)
49:22,137 INFO  [STDOUT] Hibernate: insert into Integrante (descricao, nome, email, operadorInclusao, dataHoraInclusao, operadorAlteracao, dataHoraAlteracao, versaoRegistro, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?)
49:22,137 INFO  [STDOUT] Hibernate: insert into Usuario (senha, id) values (?, ?)
49:22,168 INFO  [STDOUT] Hibernate: insert into Integrante (descricao, nome, email, operadorInclusao, dataHoraInclusao, operadorAlteracao, dataHoraAlteracao, versaoRegistro, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?)
49:22,168 INFO  [STDOUT] Hibernate: insert into Grupo (id) values (?)
49:22,184 INFO  [STDOUT] Hibernate: insert into Integrante (descricao, nome, email, operadorInclusao, dataHoraInclusao, operadorAlteracao, dataHoraAlteracao, versaoRegistro, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?)
49:22,184 INFO  [STDOUT] Hibernate: insert into Usuario (senha, id) values (?, ?)
49:22,199 INFO  [STDOUT] Hibernate: insert into Integrante (descricao, nome, email, operadorInclusao, dataHoraInclusao, operadorAlteracao, dataHoraAlteracao, versaoRegistro, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?)
49:22,215 INFO  [STDOUT] Hibernate: insert into Usuario (senha, id) values (?, ?)
49:22,215 INFO  [STDOUT] Hibernate: insert into Integrante (descricao, nome, email, operadorInclusao, dataHoraInclusao, operadorAlteracao, dataHoraAlteracao, versaoRegistro, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?)
49:22,230 INFO  [STDOUT] Hibernate: insert into Usuario (senha, id) values (?, ?)
[b]17:49:22,246 INFO  [STDOUT] Hibernate: insert into GrupoIntegrante (integranteId, grupoId) values (?, ?)[/b]

I would imagine that it display five entries for code that link group and users. But not. Only one entrie was logged!
1) Why the log shows only one entrie for GrupoIntegrante?
2) How to know the number of inserts executed in GrupoIntegrante?
3) Is it possible modify this behavior, showing all commands?
4) And finally, how I can log the values (and not "?") in commands?

Thanks for all and sorry my bad english. This text was translated with Babelfish :-)

sdknott · **Joined:** Tue Oct 07, 2003 10:20 am **Posts:** 77

It only displays one entry as it's doing a batch insert. To display the values which are bound, you need to set up Log4J, and set the following package to debug level:

Code:

log4j.logger.net.sf.hibernate.type=debug

That will show you which values are being bound to the question marks in the prepared statements.

If you really want it to see every SQL statement, then you need to do two things. Firstly set the following hibernate property:

Code:

hibernate.jdbc.batch_size 0

Secondly, use P6Spy (a link can be found at http://www.hibernate.org/27.html#A6) - this will generate a log, which will contain all the information you need. Please note that you shouldn't keep the batch level set to zero once your application goes into production!