2017-12-26 121 views
6

Mam repozytorium Spring Data JPA przy użyciu dostawcy Hibernate. Chciałbym logować instrukcje SQL, ale nie mogę tego osiągnąć. Próbowałem różnych rozwiązań:Aktywuj instrukcje SQL logujące się przy użyciu Hibernate i danych sprężynowych JPA

  • zestaw showSql true w moim HibernateJpaVendorAdapter
  • Dodaj log4j.logger.org.hibernate.SQL = DEBUG do mojego pliku log4j.properties (warto wspomnieć, że log4j.logger.org. hibernacja = INFO nie dodać trochę rejestrowania informacji, ale log4j.logger.org.hibernate.SQL = DEBUG nie)

Oto moje klas i pliki konfiguracyjne:

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 

Dlaczego jest to, że dotychczasowe rozwiązania nie działa? Czy istnieje jakaś niezgodność między konfiguracją rejestrowania Spring Data JPA i Hibernate SQL?

EDYCJA: Próbowałem obu rozwiązań zaproponowanych w komentarzach, ale żaden z nich nie działał. Próbowałem także zmienić bazę danych, której używałem (H2 dla HSQL) lub określić dialekt Hibernacji, ale to nie zadziałało. W rzeczywistości dialekt Hibernacja jest automatycznie odnajdywany dla niektórych baz danych podczas korzystania ze Springa.

EDIT 2: Próbowałem zmienić poziom rejestrowania rootLoggera na TRACE. Próbuję również wyraźnie określić próg dla aplikanta. I w końcu próbowałem dodać JpaProperties z showSql = true, ale żaden z nich nie poradził sobie. Myślę, że jest coś bardzo oczywistego do zrobienia, czego mi brakuje, aby odblokować całą sytuację: -/

EDIT 3: Zadzwonienie do rejestratora bezpośrednio, jak w poniższym teście, działa. Zacząłem się zastanawiać, czy istnieje literówka lub coś, co powstrzymuje Hibernate przed używaniem rejestratora.

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

Oto wynikające kłody:

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[email protected]1f28c152, org.springframewor[email protected]7d907bac, org.springfra[email protected]7791a895, org.springframew[email protected]3a5ed7a6, org.sp[email protected]6325a3ee]10:33:45,376 INFO GenericApplicationContext:589 - Refreshing [email protected]93d195: 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 [[email protected] testClass = EmployerRepositoryIT, testInstance = be.dupirefr[email protected]1460c81d, testMethod = [email protected], testException = [null], mergedContextConfiguration = [[email protected] 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 [o[email protected]5b22b970]; rollback [true] 
10:33:49,468 DEBUG SQL:83 - delete() 
10:33:49,512 INFO TransactionContext:137 - Rolled back transaction for test context [[email protected] testClass = EmployerRepositoryIT, testInstance = be.dupirefr[email protected]1460c81d, testMethod = [email protected], testException = [null], mergedContextConfiguration = [[email protected] 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 [email protected]93d195: 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: I w końcu zorientowali się, co się stało. Zauważyłem, że w nieudanych testach w dziennikach pojawiały się zapytania SQL.I przez nieznaczne dostrojenie moich właściwości log4j zobaczyłem, że pochodzą z hibernacji rejestratora, zgodnie z oczekiwaniami.

Jednak pomyślne operacje nie były wydaniem dzienników. A to dlatego, że nie docierają do bazy danych. Wszystko dzieje się w menedżerze encji, więc SQL nie jest potrzebny. Teraz wiem, że mam problem z bazą danych H2, którą muszę wymyślić.

+0

Spróbuj dodając 'logging.level.org.hibernate.SQL = DEBUG logging.level.org.hibernate.type.descriptor.sql.BasicBinder = trace' w pliku porperties i zobaczyć? –

+0

Powiedziałeś, że 'log4j.logger.org.hibernate = INFO' dodał trochę logowania, ale' log4j.logger.org.hibernate.SQL = DEBUG' nie. Czy próbowałeś ... 'log4j.logger.org.hibernate = DEBUG'? A może jest powyżej literówka? – dimwittedanimal

+0

@AhmedRaaj: Te właściwości muszą znajdować się w pliku właściwości Spring (jak application.properties). Nie mam żadnych, nie używam Spring Boot. Próbowałem dodać log4j.logger.org.hibernate.type.descriptor.sql.BasicBinder = TRACE do mojego pliku log4j.properties, ale ponieważ celem tego rejestratora jest wyświetlenie powiązanych parametrów, nie miało to żadnego skutku. –

Odpowiedz

1

Ponieważ patrząc na kod, który podałeś nie wydaje się go wyciąć, spróbuję go z niektórych wskazówek, jak do debugowania to.

  1. Zostaw zmian, jak podano w moim 1 odpowiedź na miejscu.

  2. Upewnij się, że plik właściwości, który pokazałeś, faktycznie kontroluje konfigurację rejestratora. Dla tej zmiany, na przykład, format wyjściowy i sprawdź, czy wpływa on na wynik zgodnie z oczekiwaniami.

  3. Znajdź odpowiednią instrukcję rejestrowania w trybie hibernacji. Umieść tam punkt przerwania. Debuguj, aż znajdziesz miejsce, w którym instrukcja dziennika zostanie odrzucona. Porównaj struktury danych związane z konfiguracją, aby dowiedzieć się, co dzieje się nie tak.

+0

Spróbuję :-). Nie wspominałem o tym wcześniej, ale ustawienie poziomu rejestrowania rootLoggera w TRACE dodało kilka dzienników, ale nie zapytania SQL. –

+0

Próbowałem umieścić punkt przerwania pierwszej linii mojego testu i pobrać tam rejestrator org.hibernate.SQL. Wygląda na dobrze skonfigurowany. Wciąż próbuję uzyskać zapis logujący w klasach hibernacji, ale to nie jest takie proste, jak się wydaje :-) –

+0

Nie miałem czasu na dalsze kopanie i nadal nie mam rozwiązania. Ale biorąc pod uwagę ilość pomocy, jaką mi dałeś, postanowiłem nagrodzić cię nagrodą za to pytanie :-) –

3

Wymienić:

log4j.rootLogger=INFO, stdout 

Z

log4j.rootLogger=TRACE, stdout 

I ewentualnie dodać

log4j.logger.org.hibernate.type.descriptor.sql=TRACE 

Jeśli chcesz wartości zmiennych powiązań, jak również.

Miałeś rejestrowanie skonfigurowany poprawnie, ale Twój appender było tylko podniesienie INFO i SQL są rejestrowane na DEBUG

+0

To wydaje się rzeczywiście uzasadnione :-).Spróbuję tego dziś wieczorem i wrócę do ciebie z wynikiem! –

+0

Po prostu próbowałem, ale to nie zadziałało. Myślenie o tym było spodziewane, ponieważ zmienia tylko poziom rejestrowania głównego rejestratora, a nie próg aplikanta (który również próbowałem zmienić, ale też nie działał). Dzięki za spróbuj. –

+0

Nie wiesz, co masz na myśli przez próg dodatku. Program udostępniający nie ma takiego, z wyjątkiem konfiguracji konfiguratora głównego. –

1

Spróbuj z tym:

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

private Properties properties() { 
    Properties properties = new Properties(); 
    properties.put("hibernate.show_sql", "true"); 
    properties.put("hibernate.format_sql", "true"); 
    return properties; 
} 

UPDATE

miałem podobna klasa konfiguracyjna jak twoja, ponieważ jestem aktualizacją wiosennego rozruchu, usunąłem tę klasę i przeniosłem całą konfigurację do pliku application.properties. Mój config to:

#DataSource 
spring.datasource.driver-class-name=org.postgresql.Driver 
spring.datasource.url=jdbc:postgresql://localhost:5432/mydb 
spring.datasource.username=postgres 
spring.datasource.password=123456 

#Hibernate 
spring.jpa.properties.hibernate.show_sql=true 
spring.jpa.properties.hibernate.format_sql=true 
spring.jpa.properties.hibernate.jdbc.batch_size=10 
spring.jpa.properties.hibernate.id.new_generator_mappings=true 

spring.jpa.properties.hibernate.dialect=org.hibernate.dialect.PostgreSQLDialect 
spring.jpa.properties.hibernate.current_session_context_class=org.springframework.orm.hibernate5.SpringSessionContext 
+0

Nie działa również :-( –

+0

zapoznaj się z moją aktualizacją –

+0

Masz kilka rzeczy więcej niż ja (kontekst dialektu lub sesji), ale czy są one powiązane z problemem? Dialekt nie jest, jest automatycznie znaleziony przez wiosnę (i próbowałem to wyraźnie określić na wszelki wypadek, nic nie zmieniłem) –

Powiązane problemy