Java & Spring Boot DB Lecture Java & JPA & Hibernate

고성능 JPA & Hibernate - Logging SQL Statements

Hibernate Logging에 대하여...

Jul 04, 2025

고성능 JPA & Hibernate - Logging SQL Statements

Contents

Statement Logging이 필요한 이유 Hibernate 로그 기반 구성 JDBC DataSource-Proxy VS Hibernate

Statement Logging이 필요한 이유 1. 자동 생성된 SQL 2. 비즈니스 로직의 완성도 3. 운영적 리스크 차단 Hibernate 로그 기반 구성 1. 기반 구성 속성 2. Hibernate의 로깅 방식 3. 바인딩 파라미터 JDBC DataSource-Proxy VS Hibernate 1. Java EE vs Spring Boot의 DataSource 관리 차이

High-Performance JPA & Hibernate Course | vladmihalcea - Inflearn

vladmihalcea | Is your Java persistence application a well-built, high-performance enterprise application, or slow code that just barely runs? The diffe

https://www.inflearn.com/course/vlad-high-performance-java-persistence/dashboard

고성능 JPA & Hibernate (High-Performance Java Persistence)를 수강하고 개인적으로 정리한 글 입니다.

고성능 JPA & Hibernate - Logging SQL Statements

JPA와 Hibernate를 사용하면서 가장 중요하지만 자주 놓치는 부분이 바로 SQL 로깅입니다. 왜 SQL 로깅이 필수일까요? 그리고 어떻게 효과적으로 설정하는 걸까요?

Statement Logging이 필요한 이유

1. 자동 생성된 SQL

Hibernate는 편리하지만, 개발자가 예상하지 못한 SQL을 생성할 수 있습니다.

문제점

Hibernate가 내부적으로 SQL을 생성하므로 개발자가 실제 실행되는 쿼리를 모름
예상과 전혀 다른 비효율적인 쿼리가 생성될 가능성
예시:


// 개발자가 작성한 JPA 코드
List<User> users = userRepository.findAll();
for(User user : users) {
    System.out.println(user.getOrders().size()); // N+1 발생!
}

// 실제 실행되는 SQL (로깅으로만 확인 가능)
SELECT * FROM users;           -- 1번
SELECT * FROM orders WHERE user_id = 1;  -- N번
SELECT * FROM orders WHERE user_id = 2;
// ... 사용자 수만큼 반복

자동 생성된 SQL에 대한 모니터링은 보이지 않는 것은 최적화할 수 없다라는 핵심적인 가치에 기인합니다.

2. 비즈니스 로직의 완성도

비즈니스 로직 구현 시, 완료 기준(Definition of Done)에 데이터 액세스 레이어 작업 검토가 포함되어야 합니다. 기능이 동작한다고 끝이 아니기 때문에, 실제로 실행되는 SQL까지 검토해야 진정한 완료로 볼 수 있습니다.

그런 의미에서 성능 문제를 개발 단계에서 원천 차단하는 것이 좋습니다.

3. 운영적 리스크 차단

예상치 못한 DB 커넥션 풀 고갈

슬로우 쿼리로 인한 서비스 응답 지연

메모리 부족으로 인한 장애

위와 같은 문제점들에 대한 해답으로 SQL Logging은 필수적입니다. SQL Logging을 효과적으로 수행했다면 얻을 수 있는 이점은 다음과 같습니다.

문제 유형	사전 발견 방법	운영 리스크 감소
N+1 쿼리	로그에서 반복적인 SELECT 확인	DB 부하 80% 감소
카테시안 곱	JOIN 결과 건수 비정상적 증가 확인	메모리 오버플로우 방지
Missing Index	실행 계획 분석으로 Full Scan 발견	쿼리 성능 10배 개선

Hibernate 로그 기반 구성

1. 기반 구성 속성

Hibernate는 로그 기반 구성 속성 3가지를 제공합니다.

hibernate.show_sql

기능: SQL 문을 콘솔에 출력
단점: 사용하지 말 것! (Should be avoided)

성능에 부정적 영향
로그 레벨 제어가 불가능
운영 환경에서 콘솔 출력은 부적절
로깅 프레임워크를 사용하는 것이 더 적절

hibernate.format_sql (제일 권장, 운영환경에서도 사용 가능)

기능: SQL 문을 보기 좋게 포맷팅

성능에 거의 영향이 없이, 로그 포맷팅 할때만 사용

사용법: 로깅이나 콘솔 출력 전에 SQL을 들여쓰기하여 가독성 향상
예시:


/* 포맷팅 전 */
SELECT u.id, u.name FROM users u WHERE u.id = ?

/* 포맷팅 후 */
SELECT 
    u.id, 
    u.name 
FROM 
    users u 
WHERE 
    u.id = ?

hibernate.use_sql_comments

기능: 자동 생성된 SQL에 주석 추가
장점:

어떤 엔티티/메서드에서 SQL이 생성되었는지 추적 가능
디버깅 시 매우 유용

단점:

SQL 문의 크기가 증가 → 네트워크 전송량 증가
주석 생성을 위한 CPU 오버헤드
네트워크 I/O 추가 비용이 있기 때문에, 운영환경에서는 사용 지양

예시:




sql
/* select com.example.User */
SELECT u.id, u.name FROM users u WHERE u.id = ?

여기서 잠깐 짚고 가야할 부분은 왜 로깅 프레임워크를 사용해야 할까요?


// 시스템 출력 (피해야 할 방식)
System.out.println("사용자 정보: " + user);
hibernate.show_sql=true  // 이것도 시스템 출력

// 로깅 프레임워크 (권장 방식)
log.info("사용자 정보: {}", user);
logging.level.org.hibernate.SQL=DEBUG

로그레벨 제어 가능하기 때문입니다.

DEBUG: 개발 환경에서만 SQL 출력
INFO: 일반적인 정보만 출력
ERROR: 오류만 출력

성능상과 운영상의 이점을 가져올 수 있습니다.

로그 레벨에 따라 처리 여부 결정
운영 환경에서 불필요한 출력 방지
로그 포맷 커스터마이징이 가능합니다.
파일로 저장 가능합니다.


# 이렇게 사용을 피해야 합니다.
hibernate.show_sql=true

# 이렇게 사용하는 것이 권장됩니다.
logging.level.org.hibernate.SQL=DEBUG
logging.level.org.hibernate.type.descriptor.sql.BasicBinder=TRACE

2. Hibernate의 로깅 방식

Hibernate의 로깅 방식은 아래와 같습니다.

JBoss Logging 라이브러리를 사용

SLF4J처럼 로깅 브리지 역할

실제 로깅 구현체와 연결해주는 중간 계층

그래서 Hibernate와 잘 통합될 수 있는 로깅 프레임워크는

Log4j / Log4j 2

예시:


<Logger name="org.hibernate.SQL" level="DEBUG"/>
<Logger name="org.hibernate.type.descriptor.sql.BasicBinder" level="TRACE"/>

LogBack(SLF4J)

예시:


<logger name="org.hibernate.SQL" level="DEBUG"/>
<logger name="org.hibernate.type.descriptor.sql.BasicBinder" level="TRACE"/>

Java Util Logging(JUL)

예시:


# logging.properties
org.hibernate.SQL.level=FINE
org.hibernate.type.descriptor.sql.BasicBinder.level=FINER


Hibernate → JBoss Logging → SLF4J → 실제 로깅 프레임워크

Log4j / LogBack / Java Util Logging이 있고, Hibernate가 제공하는 JBoss Logging의 추상화 계층을 통해 Hibernate는 다른 로깅 프레임워크와의 통합을 지원합니다.

3. 바인딩 파라미터

기본적인 Statement는 바인딩된 파라미터의 값을 알 수 없습니다. 이는 Hibernate의 바인딩 파라미터 옵션 활성화 설정을 통해 해결할 수 있습니다.


# properties
logging.level.org.hibernate.type.descriptor.sql.BasicBinder=TRACE

Hibernate의 바인딩 파라미터는 다음과 같은 특징이 있습니다.

장점: 표준화된 방식, 모든 드라이버에서 동일

특징: Statement와 바인딩 값을 분리해서 출력

Hibernate의 바인딩 파라미터 옵션외에도 P6Spy라는 대안도 존재하는데, P6Spy는 실제 실행되는 완성된 SQL문을 캡처하는 방식으로 실제 값으로 치환된 상태로 출력가능하며 Java EE나 JDBC 레이어 수준에서도 동작합니다.

실제 치환된 SQL문 캡처

타임스탬프, statement 실행 시간, 유형, 사용된 데이터베이스 세션 등 다양한 정보를 포함 가능


Application → P6Spy → JDBC Driver → Database
             (SQL 가로채기)
             
1678901234567|15|statement|connection 1|SELECT u1_0.id,u1_0.email,u1_0.name FROM users u1_0 WHERE u1_0.id=123
1678901234582|23|statement|connection 1|SELECT o1_0.user_id,o1_0.id,o1_0.order_date,o1_0.total_amount FROM orders o1_0 WHERE o1_0.user_id=123

다만 이 바인딩 파라미터 옵션은 기록된 로그의 유출로 민감 정보가 노출될 수도 있기 때문에 사용에 주의해야 합니다.


SELECT * FROM users WHERE email = ? AND password = ?
binding parameter [1] as [VARCHAR] - [admin@company.com]
binding parameter [2] as [VARCHAR] - [mySecretPassword123!]  -- 비밀번호 유출

SELECT * FROM payment WHERE card_number = ?
binding parameter [1] as [VARCHAR] - [4532-1234-5678-9012]  -- 신용카드 번호 유출

따라서 사용하고 싶다면 환경별로 로깅 레벨을 분리해서 사용하는 것을 권장합니다.


# 개발 환경 (application-dev.properties)
logging.level.org.hibernate.type.descriptor.sql.BasicBinder=TRACE

# 운영 환경 (application-prod.properties)  
logging.level.org.hibernate.type.descriptor.sql.BasicBinder=OFF # 비활성화

JDBC DataSource-Proxy VS Hibernate

기본적으로 Hibernate의 기본 로깅만으로는 한계가 있습니다. 만약 batch query를 실행시킨다고 했을 때 바인딩 파라미터를 옵션을 활성화 한다고 하더라도


Hibernate: INSERT INTO post (title, content) VALUES (?, ?)
binding parameter [1] as [VARCHAR] - [Title1]
binding parameter [2] as [VARCHAR] - [Content1]

이것이 개별 statement인지 batch인지 구분이 어렵습니다.

하지만, DataSource-Proxy는 다릅니다. 일반적인 삽입과 batch 작업시 로그가 달라지게 되는데,


@Test
public void testBatch() {
   ...
} # Batch Insert

2025-07-07 20:51:16,289 DEBUG [Alice]: n.t.d.l.l.SLF4JQueryLoggingListener - 
Name:DATA_SOURCE_PROXY, Connection:4, Time:0, Success:True, Type:Prepared, Batch:True, QuerySize:1, BatchSize:3, 
Query:["insert into post (title,id) values (?,?)"], 
Params:[(Post no. 1, 1), (Post no. 2, 2), (Post no. 3, 3)]

이런식으로 Batch:True / QuerySize / BatchSize 등의 로깅된 설명을 통해 실제 Batch가 실행됐는지 확인할 수 있습니다.

만약 DataSource-Proxy가 아니라, Hibernate였다면


Hibernate: insert into post (title,id) values (?,?)
binding parameter [1] as [VARCHAR] - [Post no. 1]
binding parameter [2] as [BIGINT] - [1]
Hibernate: insert into post (title,id) values (?,?)
binding parameter [1] as [VARCHAR] - [Post no. 2]  
binding parameter [2] as [BIGINT] - [2]
Hibernate: insert into post (title,id) values (?,?)
binding parameter [1] as [VARCHAR] - [Post no. 3]
binding parameter [2] as [BIGINT] - [3]

이런식의 로깅이 확인될될 것이고, 실제로 Batch 작업이 돌아갔는지 명확히 확인하기가 어려워집니다.

따라서 DataSource-Proxy를 사용하면 다음과 같은 장점을 얻을 수 있습니다.

다양한 메타데이터


Name:DATA_SOURCE_PROXY     ← 데이터소스 식별
Connection:4               ← 커넥션 풀 추적
Time:0                     ← 정확한 실행 시간
Success:True               ← 실행 결과 상태
Type:Prepared              ← Statement 타입
Batch:True                 ← 배치 여부
QuerySize:1                ← SQL 문 개수  
BatchSize:3                ← 배치 크기

Connection Pool의 사용 패턴을 추적할 수 있습니다.


Connection:2 → DROP TABLE 실행
Connection:3 → CREATE TABLE 실행  
Connection:4 → INSERT 배치 실행 (BatchSize:3)
Connection:5 → 테스트 정리용 DROP TABLE

따라서 DataSource-Proxy를 사용하는 것이 SQL 실행 전략을 세우는데 더 도움이 될 수 있습니다.


# 엔티티가 1:N 관계로 Lazy 로딩일 때
@ManyToOne(fetch = FetchType.LAZY)
private Post post;

# QuerySize 1
Query:["select pc1_0.id,pc1_0.post_id,pc1_0.review from post_comment pc1_0"], Params:[()]


# 엔티티가 1:N 관계에서 Eager로 변경됐을 때
@ManyToOne(fetch = FetchType.EAGER)
private Post post;

-- 1번 쿼리 - 모든 Comment 조회
Query:["select pc1_0.id,pc1_0.post_id,pc1_0.review from post_comment pc1_0"], Params:[()]

-- +N번 쿼리 - Post 1 개별 조회  
Query:["select p1_0.id,p1_0.title from post p1_0 where p1_0.id=?"], Params:[(1)]

-- +N번 쿼리 - Post 2 개별 조회
Query:["select p1_0.id,p1_0.title from post p1_0 where p1_0.id=?"], Params:[(2)]

위처럼 만약 N + 1문제가 발생했을 때도 SQLStatementCountValidator 가 기본적으로 모든 statement를 집계하는 DataSourceProxy의 QueryCountHolder에 의존하기 때문에


SQLStatementCountValidator.assertSelectCount(1);

예상과 다른 쿼리 실행결과가 나타나게 되면 바로 알 수 있게 됩니다. 따라서, N+1 문제를 개발 단계에서 원천 차단할 수 있게 됩니다.

결론적으로 Hibernate와 DataSource를 비교하면 다음과 같습니다.

분석 항목	Hibernate 로깅	DataSource-Proxy (실제 로그)
배치 감지	❌ 불가능	✅ BatchSize:3 명시적 표시
파라미터 통합	❌ 분리된 로그	✅ Params:[(Post no. 1, 1), (Post no. 2, 2)]
커넥션 추적	❌ 불가능	✅ Connection:4 명시적 추적
실행 시간	❌ 부정확	✅ Time:0 정확한 측정
실행 결과	❌ 불가능	✅ Success:True 상태 확인
즉시 실행 가능	❌ 조합 필요	✅ 완성된 SQL + 파라미터

그렇기 때문에 JDBC DataSource-Proxy가 Hibernate 로깅보다 훨씬 더 유연한 대안입니다.

1. Java EE vs Spring Boot의 DataSource 관리 차이

물론 DataSource-Porxy를 아무데서나 사용할 수 있는 것은 아닙니다. 기본적으로 Java EE나 JakartaEE 환경, 즉 Spring이나 Spring Boot를 사용하지 않는 환경에서는 JNDI로 관리되는 DataSource 문제 때문에 사용이 어렵습니다.

Proxy 설정이 상당히 복잡하고, persistence.xml로 고정된 설정과 WAS(Web Application Server) 제어권 문제 때문에 사용을 권장드리지 않습니다.

Spring Boot 환경에서는 DataSource-Proxy를 쉽게 적용할 수 있습니다. Java EE 환경에서는 JNDI 설정의 복잡성으로 인해 권장하지 않습니다.

DataSource-Proxy 어떻게 사용하면 좋을까?

라이브러리 설치


implementation 'net.ttddyy:datasource-proxy:1.10'

DataSourceProxy 등록


@Configuration
public class DataSourceProxyConfig {

    @Bean
    @Primary
    public DataSource dataSource(DataSourceProperties properties) {
        DataSource dataSource = properties.initializeDataSourceBuilder().build();

        return ProxyDataSourceBuilder
                .create(dataSource)
                .name("DataSourceProxy")
                .logQueryBySlf4j(SLF4JLogLevel.INFO)
                .logSlowQueryBySlf4j(300, TimeUnit.MILLISECONDS, SLF4JLogLevel.WARN)
                .multiline()
                .countQuery()
                .build();
    }
}

Spring Boot에서 DataSource-Proxy + Hibernate 로깅 섞어 쓰면 될 것 같습니다.

See more posts