使用Hibernate和Spring Data JPA激活SQL语句

Question

我有一个使用Hibernate作为提供程序的Spring Data JPA存储库.我想记录SQL语句,但我无法实现.我试过各种解决方案:

• 在我的HibernateJpaVendorAdapter中将showSql设置为true
• 将log4j.logger.org.hibernate.SQL = DEBUG添加到我的log4j.properties文件中(值得一提的是log4j.logger.org.hibernate = INFO确实添加了一些日志信息但log4j.logger.org.hibernate.SQL = DEBUG didn "t)的

这是我的类和配置文件:

DatabaseConfiguration.java

/**
 * Database configuration
 *
 * @author dupirefr
 */
@Configuration
@Import({BaseConfiguration.class, DatabaseProperties.class})
@EnableJpaRepositories(basePackages = DatabaseConfiguration.REPOSITORIES_PACKAGE)
public class DatabaseConfiguration {

    /*
     * Constants
     */
    public static final String MODEL_PACKAGE = "be.dupirefr.examples.spring.batch.simple.model";
    public static final String REPOSITORIES_PACKAGE = "be.dupirefr.examples.spring.batch.simple.repositories";

    /*
     * Beans
     */
    @Bean
    public DataSource dataSource(DatabaseProperties properties) {
        DriverManagerDataSource dataSource = new DriverManagerDataSource();
        dataSource.setUrl(properties.url);
        dataSource.setUsername(properties.username);
        dataSource.setPassword(properties.password);
        dataSource.setDriverClassName(properties.driverClassName);

        return dataSource;
    }

    @Bean
    public LocalContainerEntityManagerFactoryBean entityManagerFactory(DataSource dataSource) {
        LocalContainerEntityManagerFactoryBean entityManagerFactoryBean = new LocalContainerEntityManagerFactoryBean();
        entityManagerFactoryBean.setDataSource(dataSource);
        entityManagerFactoryBean.setPackagesToScan(MODEL_PACKAGE);
        entityManagerFactoryBean.setJpaVendorAdapter(new HibernateJpaVendorAdapter());
        return entityManagerFactoryBean;
    }

    @Bean
    public PlatformTransactionManager transactionManager(DataSource dataSource) {
        return new DataSourceTransactionManager(dataSource);
    }

}

database.properties

# Data source
spring.datasource.url=jdbc:h2:mem:test
spring.datasource.username=admin
spring.datasource.password=admin
spring.datasource.driver-class-name=org.h2.Driver

DatabaseProperties.java

/**
 * Database properties
 *
 * @author dupirefr
 */
@Configuration
@PropertySource("classpath:be/dupirefr/examples/spring/batch/simple/config/database/database.properties")
public class DatabaseProperties {

    /*
     * Fields
     */
    @Value("${spring.datasource.url}")
    public String url;

    @Value("${spring.datasource.username}")
    public String username;

    @Value("${spring.datasource.password}")
    public String password;

    @Value("${spring.datasource.driver-class-name}")
    public String driverClassName;

}

EmployerRepository.java

/**
 * {@link Employer}'s repository
 *
 * @author dupirefr
 */
@Repository
public interface EmployerRepository extends JpaRepository<Employer, Long> {

}

EmployerRepositoryIT.java

/**
 * {@link EmployerRepository}'s integration test
 *
 * @author dupirefr
 */
@RunWith(SpringRunner.class)
@ContextConfiguration(classes = DatabaseConfiguration.class)
@Transactional
public class EmployerRepositoryIT {

    /*
     * Constants
     */
    public static final Employer GOOGLE = new Employer(1L, "Google");
    public static final Employer MICROSOFT = new Employer(2L, "Microsoft");
    public static final Employer APPLE = new Employer(3L, "Apple");

    /*
     * Fields
     */
    @Autowired
    private EmployerRepository repository;

    @Autowired
    private EntityManager entityManager;

    /*
     * Setups
     */
    @Before
    public void setUp() {
        entityManager.persist(GOOGLE);
        entityManager.persist(MICROSOFT);
    }

    /*
     * Tests
     */
    @Test
    public void findById_Exists() {
        assertEquals(GOOGLE, repository.findById(GOOGLE.getId()).get());
        assertEquals(MICROSOFT, repository.findById(MICROSOFT.getId()).get());
    }

    @Test
    public void findById_NotExists() {
        assertFalse(repository.findById(Long.MAX_VALUE).isPresent());
    }

    @Test
    public void findAll() {
        assertEquals(Arrays.asList(GOOGLE, MICROSOFT), repository.findAll());
    }

    @Test
    public void save() {
        repository.save(APPLE);
        assertEquals(APPLE, entityManager.find(Employer.class, APPLE.getId()));
    }

    @Test
    public void delete() {
        repository.delete(MICROSOFT);
        assertNull(entityManager.find(Employer.class, MICROSOFT.getId()));
    }

}

log4j.properties

# Appenders
## Console
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.Target=System.out
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%d{ABSOLUTE} %5p %c{1}:%L - %m%n

# Loggers
## Root
log4j.rootLogger=INFO, stdout

## Hibernate
### Generic
log4j.logger.org.hibernate=INFO
### SQL statements
log4j.logger.org.hibernate.SQL=DEBUG

为什么以前的解决方案不起作用？Spring Data JPA和Hibernate SQL日志配置之间是否存在某种不兼容性？

编辑:我尝试了评论中提出的两个解决方案,但没有一个工作.我还尝试更改我正在使用的数据库(H2 for HSQL)或指定Hibernate方言,但这不起作用.事实上,在使用Spring时,某些数据库会自动找到Hibernate方言.

编辑2:我试图将rootLogger的日志记录级别更改为TRACE.我还尝试明确指定appender的阈值.最后我尝试使用showSql = true添加JpaProperties,但没有一个能够实现.我认为有一些非常明显的事情可以让我解开完整的情况: - /

编辑3:直接调用记录器,如下面的测试确实有效.我开始怀疑是否存在打字错误或阻止Hibernate使用记录器的东西.

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

以下是生成的日志:

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'

编辑3:我终于弄清楚发生了什么.我注意到在失败的测试中,SQL查询是在日志中发出的.通过调整我的log4j属性,我看到它们来自hibernate logger,正如预期的那样.

但成功的操作并不是发布日志.那是因为他们没有到达数据库.一切都在实体管理器中发生,因此不需要SQL.现在我知道我的H2数据库存在问题,我需要弄清楚.

Answer 1

由于查看您提供的代码似乎并没有解决问题，因此我将尝试使用一些说明来调试它。

1. 保留我在第一个答案中给出的更改。

2. 确保您显示的属性文件实际上控制记录器配置。例如，对于此更改，输出格式并检查它是否按预期影响输出。

3. 在 Hibernate 中查找相关的日志记录语句。在那里放置一个断点。调试直到找到日志语句被丢弃的地方。比较与您的配置相关的数据结构以了解出了什么问题。