Skip to main content
added 471 characters in body
Source Link
fddev
  • 615
  • 3
  • 13
  • 33

EDIT 3: I finally figured out what happen. I noticed that on failed tests SQL queries were issued in the logs. And by tuning a little bit my log4j properties I saw they came from hibernate logger, as expected.

But successful operations were not issuing logs. And that's because they don't reach the database. Everything happens within the entity manager and so no SQL is needed. Now I know that I just have a problem with my H2 database that I need to figure out.

EDIT 3: I finally figured out what happen. I noticed that on failed tests SQL queries were issued in the logs. And by tuning a little bit my log4j properties I saw they came from hibernate logger, as expected.

But successful operations were not issuing logs. And that's because they don't reach the database. Everything happens within the entity manager and so no SQL is needed. Now I know that I just have a problem with my H2 database that I need to figure out.

Notice removed Draw attention by fddev
Bounty Ended with Jens Schauder's answer chosen by fddev
Added resulting logs
Source Link
fddev
  • 615
  • 3
  • 13
  • 33

EDIT 3 : Calling the logger directly as in the following test did work. I became to wonder if there is a typo or something that prevent Hibernate to use the logger.

@Test public void delete() { LoggerFactory.getLogger("org.hibernate.SQL").debug("delete()"); repository.delete(MICROSOFT); assertNull(entityManager.find(Employer.class, MICROSOFT.getId())); } 

Here are the resulting logs:

10:33:45,158 INFO DefaultTestContextBootstrapper:257 - Loaded default TestExecutionListener class names from location [META-INF/spring.factories]: [org.springframework.test.context.web.ServletTestExecutionListener, org.springframework.test.context.support.DirtiesContextBeforeModesTestExecutionListener, org.springframework.test.context.support.DependencyInjectionTestExecutionListener, org.springframework.test.context.support.DirtiesContextTestExecutionListener, org.springframework.test.context.transaction.TransactionalTestExecutionListener, org.springframework.test.context.jdbc.SqlScriptsTestExecutionListener] 10:33:45,183 INFO DefaultTestContextBootstrapper:206 - Could not instantiate TestExecutionListener [org.springframework.test.context.web.ServletTestExecutionListener]. Specify custom listener classes or make the default listener classes (and their required dependencies) available. Offending class: [javax/servlet/ServletContext] 10:33:45,185 INFO DefaultTestContextBootstrapper:184 - Using TestExecutionListeners: [org.springframework.test.context.support.DirtiesContextBeforeModesTestExecutionListener@1f28c152, org.springframework.test.context.support.DependencyInjectionTestExecutionListener@7d907bac, org.springframework.test.context.support.DirtiesContextTestExecutionListener@7791a895, org.springframework.test.context.transaction.TransactionalTestExecutionListener@3a5ed7a6, org.springframework.test.context.jdbc.SqlScriptsTestExecutionListener@6325a3ee]10:33:45,376 INFO GenericApplicationContext:589 - Refreshing org.springframework.context.support.GenericApplicationContext@4493d195: startup date [Sun Jan 14 10:33:45 CET 2018]; root of context hierarchy 10:33:46,187 WARN ConfigurationClassEnhancer:353 - @Bean method BaseConfiguration.propertySourcesPlaceholderConfigurer is non-static and returns an object assignable to Spring's BeanFactoryPostProcessor interface. This will result in a failure to process annotations such as @Autowired, @Resource and @PostConstruct within the method's declaring @Configuration class. Add the 'static' modifier to this method to avoid these container lifecycle issues; see @Bean javadoc for complete details. 10:33:46,448 INFO DriverManagerDataSource:133 - Loaded JDBC driver: org.h2.Driver 10:33:46,743 INFO LocalContainerEntityManagerFactoryBean:361 - Building JPA container EntityManagerFactory for persistence unit 'default' 10:33:46,798 INFO LogHelper:31 - HHH000204: Processing PersistenceUnitInfo [ name: default ...] 10:33:46,922 INFO Version:45 - HHH000412: Hibernate Core {5.2.12.Final} 10:33:46,924 INFO Environment:213 - HHH000206: hibernate.properties not found 10:33:46,979 INFO Version:66 - HCANN000001: Hibernate Commons Annotations {5.0.1.Final} 10:33:47,318 INFO Dialect:157 - HHH000400: Using dialect: org.hibernate.dialect.H2Dialect 10:33:48,472 INFO LocalContainerEntityManagerFactoryBean:393 - Initialized JPA EntityManagerFactory for persistence unit 'default' 10:33:49,422 INFO TransactionContext:105 - Began transaction (1) for test context [DefaultTestContext@2e3f79a2 testClass = EmployerRepositoryIT, testInstance = be.dupirefr.examples.spring.batch.simple.repositories.EmployerRepositoryIT@1460c81d, testMethod = delete@EmployerRepositoryIT, testException = [null], mergedContextConfiguration = [MergedContextConfiguration@38b5f25 testClass = EmployerRepositoryIT, locations = '{}', classes = '{class be.dupirefr.examples.spring.batch.simple.config.database.DatabaseConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[[empty]], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]], attributes = map[[empty]]]; transaction manager [org.springframework.jdbc.datasource.DataSourceTransactionManager@5b22b970]; rollback [true] 10:33:49,468 DEBUG SQL:83 - delete() 10:33:49,512 INFO TransactionContext:137 - Rolled back transaction for test context [DefaultTestContext@2e3f79a2 testClass = EmployerRepositoryIT, testInstance = be.dupirefr.examples.spring.batch.simple.repositories.EmployerRepositoryIT@1460c81d, testMethod = delete@EmployerRepositoryIT, testException = [null], mergedContextConfiguration = [MergedContextConfiguration@38b5f25 testClass = EmployerRepositoryIT, locations = '{}', classes = '{class be.dupirefr.examples.spring.batch.simple.config.database.DatabaseConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[[empty]], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]], attributes = map[[empty]]]. 10:33:49,516 INFO GenericApplicationContext:989 - Closing org.springframework.context.support.GenericApplicationContext@4493d195: startup date [Sun Jan 14 10:33:45 CET 2018]; root of context hierarchy 10:33:49,519 INFO LocalContainerEntityManagerFactoryBean:571 - Closing JPA EntityManagerFactory for persistence unit 'default' 

EDIT 3 : Calling the logger directly as in the following test did work. I became to wonder if there is a typo or something that prevent Hibernate to use the logger.

@Test public void delete() { LoggerFactory.getLogger("org.hibernate.SQL").debug("delete()"); repository.delete(MICROSOFT); assertNull(entityManager.find(Employer.class, MICROSOFT.getId())); } 

Here are the resulting logs:

10:33:45,158 INFO DefaultTestContextBootstrapper:257 - Loaded default TestExecutionListener class names from location [META-INF/spring.factories]: [org.springframework.test.context.web.ServletTestExecutionListener, org.springframework.test.context.support.DirtiesContextBeforeModesTestExecutionListener, org.springframework.test.context.support.DependencyInjectionTestExecutionListener, org.springframework.test.context.support.DirtiesContextTestExecutionListener, org.springframework.test.context.transaction.TransactionalTestExecutionListener, org.springframework.test.context.jdbc.SqlScriptsTestExecutionListener] 10:33:45,183 INFO DefaultTestContextBootstrapper:206 - Could not instantiate TestExecutionListener [org.springframework.test.context.web.ServletTestExecutionListener]. Specify custom listener classes or make the default listener classes (and their required dependencies) available. Offending class: [javax/servlet/ServletContext] 10:33:45,185 INFO DefaultTestContextBootstrapper:184 - Using TestExecutionListeners: [org.springframework.test.context.support.DirtiesContextBeforeModesTestExecutionListener@1f28c152, org.springframework.test.context.support.DependencyInjectionTestExecutionListener@7d907bac, org.springframework.test.context.support.DirtiesContextTestExecutionListener@7791a895, org.springframework.test.context.transaction.TransactionalTestExecutionListener@3a5ed7a6, org.springframework.test.context.jdbc.SqlScriptsTestExecutionListener@6325a3ee]10:33:45,376 INFO GenericApplicationContext:589 - Refreshing org.springframework.context.support.GenericApplicationContext@4493d195: startup date [Sun Jan 14 10:33:45 CET 2018]; root of context hierarchy 10:33:46,187 WARN ConfigurationClassEnhancer:353 - @Bean method BaseConfiguration.propertySourcesPlaceholderConfigurer is non-static and returns an object assignable to Spring's BeanFactoryPostProcessor interface. This will result in a failure to process annotations such as @Autowired, @Resource and @PostConstruct within the method's declaring @Configuration class. Add the 'static' modifier to this method to avoid these container lifecycle issues; see @Bean javadoc for complete details. 10:33:46,448 INFO DriverManagerDataSource:133 - Loaded JDBC driver: org.h2.Driver 10:33:46,743 INFO LocalContainerEntityManagerFactoryBean:361 - Building JPA container EntityManagerFactory for persistence unit 'default' 10:33:46,798 INFO LogHelper:31 - HHH000204: Processing PersistenceUnitInfo [ name: default ...] 10:33:46,922 INFO Version:45 - HHH000412: Hibernate Core {5.2.12.Final} 10:33:46,924 INFO Environment:213 - HHH000206: hibernate.properties not found 10:33:46,979 INFO Version:66 - HCANN000001: Hibernate Commons Annotations {5.0.1.Final} 10:33:47,318 INFO Dialect:157 - HHH000400: Using dialect: org.hibernate.dialect.H2Dialect 10:33:48,472 INFO LocalContainerEntityManagerFactoryBean:393 - Initialized JPA EntityManagerFactory for persistence unit 'default' 10:33:49,422 INFO TransactionContext:105 - Began transaction (1) for test context [DefaultTestContext@2e3f79a2 testClass = EmployerRepositoryIT, testInstance = be.dupirefr.examples.spring.batch.simple.repositories.EmployerRepositoryIT@1460c81d, testMethod = delete@EmployerRepositoryIT, testException = [null], mergedContextConfiguration = [MergedContextConfiguration@38b5f25 testClass = EmployerRepositoryIT, locations = '{}', classes = '{class be.dupirefr.examples.spring.batch.simple.config.database.DatabaseConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[[empty]], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]], attributes = map[[empty]]]; transaction manager [org.springframework.jdbc.datasource.DataSourceTransactionManager@5b22b970]; rollback [true] 10:33:49,468 DEBUG SQL:83 - delete() 10:33:49,512 INFO TransactionContext:137 - Rolled back transaction for test context [DefaultTestContext@2e3f79a2 testClass = EmployerRepositoryIT, testInstance = be.dupirefr.examples.spring.batch.simple.repositories.EmployerRepositoryIT@1460c81d, testMethod = delete@EmployerRepositoryIT, testException = [null], mergedContextConfiguration = [MergedContextConfiguration@38b5f25 testClass = EmployerRepositoryIT, locations = '{}', classes = '{class be.dupirefr.examples.spring.batch.simple.config.database.DatabaseConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[[empty]], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]], attributes = map[[empty]]]. 10:33:49,516 INFO GenericApplicationContext:989 - Closing org.springframework.context.support.GenericApplicationContext@4493d195: startup date [Sun Jan 14 10:33:45 CET 2018]; root of context hierarchy 10:33:49,519 INFO LocalContainerEntityManagerFactoryBean:571 - Closing JPA EntityManagerFactory for persistence unit 'default' 
added 337 characters in body
Source Link
fddev
  • 615
  • 3
  • 13
  • 33

EDIT 2 : I tried to change logging level of the rootLogger to TRACE. I also try to specify a threshold for the appender explicitely. And finally I tried to add JpaProperties with showSql = true but none of them did the trick. I think that there is something really obvious to do that I'm missing to unlock the complete situation :-/

EDIT 2 : I tried to change logging level of the rootLogger to TRACE. I also try to specify a threshold for the appender explicitely. And finally I tried to add JpaProperties with showSql = true but none of them did the trick. I think that there is something really obvious to do that I'm missing to unlock the complete situation :-/

New solutions tried
Source Link
fddev
  • 615
  • 3
  • 13
  • 33
Loading
Notice added Draw attention by fddev
Bounty Started worth 50 reputation by fddev
Source Link
fddev
  • 615
  • 3
  • 13
  • 33
Loading