상품 리뷰 탭을 누르면 0.6초, DB가 그 SQL에 쓴 시간은 0.01초다

중급SELECT이커머스580 / 700

이 문제는 교재 18화 졸업 과제와 같은 이커머스 데이터베이스를 씁니다. 『튜너의 1년』을 순서대로 읽고 있다면 졸업 과제를 먼저 풀고 오세요. 아래 「테이블과 인덱스」 칸에 과제의 답 일부(제약 조건, 인덱스, 통계의 실제 상태)가 나옵니다.

상황

이커머스 상품 상세 화면의 「리뷰」 탭은 그 상품의 최근 리뷰 50개를 보여 준다. 리뷰마다 본문 앞 100자를 보여 주고, '더 보기'를 누르면 그 리뷰의 본문 전체를 펼친다. 지난달 API 서버를 클라우드로 옮긴 뒤로 리뷰 탭 응답이 0.6초 안팎이다. DB는 사내 IDC에 남았다. APM에는 DB 구간이 0.6초로 찍히는데, DBA가 본 그 SQL의 실행 시간은 0.01초다.

테이블과 인덱스

reviews: 15,000행 · 775블록 · content CLOB(평균 380자, 대부분 행 안에 저장된다) · 상품당 34 ~ 76건
인덱스 IX_REV_PROD_DT (product_id, created_at, review_id)(SORT-002에서 만든 인덱스) · 통계 최신
API 서버와 DB 사이의 왕복은 약 5ms다. JDBC fetch size는 기본값(10)이고, 드라이버 설정에서 LOB 미리 가져오기(LOB prefetch)는 꺼 두었다(2021년 메모리 문제 때 끔).

원본 SQL

sql

// ReviewApi.java : 최근 리뷰 50개 · 화면에는 본문 앞 100자만 쓴다
String sql = "SELECT review_id, customer_id, rating, created_at, content "
           + "FROM (SELECT review_id, customer_id, rating, created_at, content "
           + "        FROM reviews WHERE product_id = ? "
           + "       ORDER BY created_at DESC, review_id DESC) "
           + "WHERE ROWNUM <= 50";
PreparedStatement ps = conn.prepareStatement(sql);
ps.setLong(1, productId);
ResultSet rs = ps.executeQuery();
while (rs.next()) {
    Clob c = rs.getClob("content");
    String body = c.getSubString(1, (int) c.length());
    item.setPreview(body.length() > 100 ? body.substring(0, 100) + "…" : body);
}

실행계획 학습용 예시

xplan

[10046 트레이스 · 리뷰 탭 한 번 (상품 1042 · 리뷰 76개 중 50개)]
  PARSE 1 · EXEC 1 · FETCH 5 (r=10 씩)
  LOBGETLEN  50번   (c.length())
  LOBREAD    50번   (c.getSubString())
  WAIT 'SQL*Net message from client'   105번 · 합계 0.57 초 (평균 5.4 ms)
  DB 안에서 쓴 시간 (EXEC + FETCH + LOB 호출 합계)   0.012 초

[세션 통계 · 같은 한 번]
  SQL*Net roundtrips to/from client      106
  lob reads                               50
  session logical reads                  153

[DISPLAY_CURSOR · 같은 실행]
------------------------------------------------------------------------------------------------------------------
| Id  | Operation                       | Name           | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                |                |      1 |        |     50 |00:00:00.01 |      53 |
|*  1 |  COUNT STOPKEY                  |                |      1 |        |     50 |00:00:00.01 |      53 |
|   2 |   VIEW                          |                |      1 |     54 |     50 |00:00:00.01 |      53 |
|   3 |    TABLE ACCESS BY INDEX ROWID  | REVIEWS        |      1 |     54 |     50 |00:00:00.01 |      53 |
|*  4 |     INDEX RANGE SCAN DESCENDING | IX_REV_PROD_DT |      1 |     54 |     50 |00:00:00.01 |       3 |
------------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter(ROWNUM<=50)
   4 - access("PRODUCT_ID"=:1)

문제

SQL은 0.01초인데 리뷰 탭이 0.6초 걸리는 이유를 트레이스와 세션 통계로 설명하시오. 왕복 106번이 어디서 나오는지 나눠 쓰시오.
화면이 바뀌지 않게(본문 앞 100자, '더 보기'는 전체) SQL과 코드를 고치고, 고친 뒤의 왕복 수를 쓰시오.

개선 SQL원본 SQL을 고쳐 쓰세요. 인덱스 DDL과 힌트도 쓸 수 있습니다.

개선 사유무엇이 문제였고 왜 이렇게 고쳤는지 쓰세요.0자

모범답안

모범 답안 SQL

sql

// ReviewApi.java : 목록은 본문 앞 100자를 VARCHAR2로 · 50행을 한 번에
String sql = "SELECT review_id, customer_id, rating, created_at, "
           + "       DBMS_LOB.SUBSTR(content, 100, 1) AS preview, "
           + "       CASE WHEN DBMS_LOB.GETLENGTH(content) > 100 THEN 'Y' ELSE 'N' END AS more_yn "
           + "FROM (SELECT review_id, customer_id, rating, created_at, content "
           + "        FROM reviews WHERE product_id = ? "
           + "       ORDER BY created_at DESC, review_id DESC) "
           + "WHERE ROWNUM <= 50";
PreparedStatement ps = conn.prepareStatement(sql);
ps.setFetchSize(51);                        // 50행 + 끝 확인 · 실행과 첫 페치 한 번에
ps.setLong(1, productId);
ResultSet rs = ps.executeQuery();
while (rs.next()) {
    item.setPreview(rs.getString("preview") + ("Y".equals(rs.getString("more_yn")) ? "…" : ""));
}

// '더 보기'를 누른 리뷰 하나만 본문 전체 (LOB 호출은 그 한 건에만)
String detail = "SELECT content FROM reviews WHERE review_id = ?";

개선 후 실행계획 학습용 예시

xplan

[리뷰 탭 한 번 · 고친 뒤 (학습용 예시)]
  PARSE 1 · EXEC 1 · FETCH 1 (r=50)
  LOBGETLEN · LOBREAD  0번 (DBMS_LOB.SUBSTR와 GETLENGTH는 DB 안에서 끝난다)
  SQL*Net roundtrips to/from client      2
  WAIT 'SQL*Net message from client'     1번 · 0.005 초
  session logical reads                 151   (본문을 자르려고 행마다 LOB을 읽는 일은 DB 안에서 그대로 한다)
  DB 안에서 쓴 시간                      0.006 초
  리뷰 탭 응답                           0.6 초 → 0.02 초

------------------------------------------------------------------------------------------------------------------
| Id  | Operation                       | Name           | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                |                |      1 |        |     50 |00:00:00.01 |      53 |
|*  1 |  COUNT STOPKEY                  |                |      1 |        |     50 |00:00:00.01 |      53 |
|   2 |   VIEW                          |                |      1 |     54 |     50 |00:00:00.01 |      53 |
|   3 |    TABLE ACCESS BY INDEX ROWID  | REVIEWS        |      1 |     54 |     50 |00:00:00.01 |      53 |
|*  4 |     INDEX RANGE SCAN DESCENDING | IX_REV_PROD_DT |      1 |     54 |     50 |00:00:00.01 |       3 |
------------------------------------------------------------------------------------------------------------------

모범 답안 서술

SQL 자체는 인덱스로 50행을 찾는 53블록짜리이고 DB 안에서 쓴 시간은 0.012초다. 나머지 0.57초는 DB가 API 서버의 다음 호출을 기다린 SQL*Net message from client(105번, 평균 5.4ms)다. 왕복 106번은 이렇게 나온다. 첫째, fetch size가 기본값 10이라 50행을 받는 데 페치가 5번이다. 둘째, CLOB 컬럼을 SELECT하면 행에는 본문 대신 위치 정보(로케이터)만 실려 오고, 본문은 클라이언트가 따로 달라고 해야 온다. LOB 미리 가져오기를 꺼 두었으므로 리뷰마다 c.length()가 길이를 묻는 호출(LOBGETLEN)을, c.getSubString()이 본문을 읽는 호출(LOBREAD)을 한 번씩 보낸다. 리뷰 50개에 100번이다. 5 + 100에 실행 한 번을 더하면 106번이고, 왕복 한 번이 약 5ms라 0.6초가 된다. IDC 안에 있던 때(왕복 0.3ms)에는 같은 106번이 0.03초여서 드러나지 않았다. 화면에 필요한 것은 본문 전체가 아니라 앞 100자다. 그래서 목록 SQL에서 DBMS_LOB.SUBSTR(content, 100, 1)로 앞 100자를 VARCHAR2로 잘라 행과 함께 보낸다. 100자가 넘는지는 DBMS_LOB.GETLENGTH로 표시만 한다. 로케이터가 오지 않으므로 LOB 호출이 사라지고, fetch size를 51로 주면 실행과 첫 페치가 한 번에 끝난다. 왕복은 106 → 2번, 리뷰 탭은 0.6 → 0.02초가 된다. 본문 전체는 '더 보기'를 누른 리뷰 하나만 review_id로 읽는다. 그 한 건에만 LOB 호출이 생긴다. DB 안의 일은 거의 그대로다. 본문을 자르려면 행마다 LOB을 읽어야 하므로 session logical reads는 153 → 151이다. 줄인 것은 블록이 아니라 네트워크를 건너는 횟수다.

해설

다른 답: 드라이버의 LOB 미리 가져오기(setLobPrefetchSize, 연결 속성 defaultLobPrefetchSize)를 리뷰 본문 길이(한글 380자, 1천 바이트 남짓)보다 크게 켜면 길이와 본문 앞부분이 로케이터와 함께 와서 LOB 호출이 사라진다. 다만 화면이 쓰지 않는 본문까지 보내고, 2021년에 끈 이유(메모리)를 다시 따져야 한다.
SUBSTR(content, 1, 100)은 CLOB에 쓰면 결과도 CLOB이라 로케이터가 그대로 온다. VARCHAR2로 받으려면 DBMS_LOB.SUBSTR(SQL에서는 4,000바이트까지)를 쓴다.
같은 함정은 TO_CLOB이나 XMLTYPE, JSON 결과를 행마다 돌려받는 목록에도 있다. 목록에서는 화면이 쓰는 만큼만 VARCHAR2로 보낸다.
네트워크를 건너는 횟수는 트레이스의 WAIT 'SQL*Net message from client' 줄 수나 세션 통계의 roundtrips로 센다. ASH에는 Idle 대기라 잡히지 않는다(교재 17화).

상황 ​

테이블과 인덱스 ​

원본 SQL ​

실행계획 학습용 예시 ​

문제 ​

모범 답안 SQL ​

개선 후 실행계획 학습용 예시 ​

모범 답안 서술 ​

해설 ​

관련 교재 ​

상황