단일 세션 정밀 진단: SQL Trace·TKPROF

핵심 요약

SQL Trace는 특정 Session이나 업무 범위에서 실행된 SQL의 Parse·Execute·Fetch Call, CPU·Elapsed Time, Logical·Physical I/O, 처리 Row 수, Library Cache Miss, Wait와 선택적 Bind 정보를 Raw Trace 파일에 기록합니다. TKPROF는 Trace 파일을 SQL 문장별로 집계하고 정렬해 읽기 쉬운 보고서로 변환합니다.

가장 작은 업무 범위 선택
  → Trace 관리 조건 확인
  → Trace 활성화
  → 문제 동작 재현
  → 즉시 비활성화
  → Trace 파일 식별·수집
  → 필요 시 TRCSESS로 병합
  → TKPROF 집계 분석
  → Raw Trace에서 시간 순서·개별 실행·Wait·Bind 재확인

두 도구의 역할은 다음과 같습니다.

SQL Trace의 핵심 질문은 다음과 같습니다.

1. Parse·Execute·Fetch 중 어느 Call에 시간이 집중됐는가?
2. CPU와 Elapsed의 차이를 어떤 Wait들이 구성했는가?
3. 한 실행·한 Row를 위해 몇 Block을 읽었는가?
4. 같은 SQL이 한 업무에서 몇 번 호출됐는가?
5. 빠른 실행과 느린 실행이 같은 집계 안에 섞였는가?
6. 실제 Trace 당시 Row Source Plan이 기록됐는가?
7. Connection Pool·RAC 환경에서 Trace가 여러 파일로 분산됐는가?

이 이론의 범위

이 이론은 SQLP의 SQL 고급활용 및 튜닝 → SQL 분석 도구 → SQL 트레이스 범위에서 SQL Trace·TKPROF·TRCSESS를 다룹니다. AWR·ASH·SQL Monitor의 장기·실시간 분석과 10053 Optimizer Trace는 후속 이론에서 다룹니다.

학습 목표

이 이론을 학습한 뒤에는 다음 내용을 설명할 수 있어야 합니다.

• SQL Trace, TKPROF, TRCSESS의 역할을 구분한다.
• Parse·Execute·Fetch Call을 SELECT와 DML 기준으로 설명한다.
• TKPROF의 count, cpu, elapsed, disk, query, current, rows를 해석한다.
• query + current가 Logical I/O인 이유를 설명한다.
• elapsed - cpu를 특정 Wait Event 하나와 바로 같다고 보면 안 되는 이유를 설명한다.
• 현재 Session과 다른 Session의 Trace 수집 방법을 구분한다.
• Connection Pool에서 Service·Module·Action·Client Identifier가 필요한 이유를 설명한다.
• plan_stat의 NEVER, FIRST_EXECUTION, ALL_EXECUTIONS를 구분한다.
• Cursor가 닫히지 않으면 Row Source 통계가 Trace·TKPROF에 나타나지 않을 수 있음을 설명한다.
• Trace 파일 위치와 식별자를 확인한다.
• TRCSESS의 Session·Client ID·Service·Module·Action 병합 기준을 설명한다.
• TKPROF의 SYS, SORT, AGGREGATE, WAITS, EXPLAIN 옵션을 올바르게 해석한다.
• TKPROF의 EXPLAIN Plan이 Trace 당시 실제 Plan과 다를 수 있음을 설명한다.
• Bind 값과 Trace 파일의 보안·크기·부하 위험을 통제한다.

1. SQL Trace가 필요한 상황

다음 상황에서는 Instance 전체 누적 통계보다 SQL Trace가 더 직접적인 근거를 제공합니다.

• 특정 화면·API·Batch만 간헐적으로 느림
• 한 Session에서 여러 SQL이 순서대로 수행됨
• Parse·Execute·Fetch 중 지연 위치를 구분해야 함
• Application이 동일 SQL을 지나치게 반복 호출하는지 확인해야 함
• Wait Event를 실제 SQL Call과 시간 순서로 연결해야 함
• Bind 값에 따라 빠른 실행과 느린 실행이 섞임
• Commit·Rollback·Recursive SQL의 위치가 필요함
• Connection Pool·Shared Server에서 업무 Trace가 여러 Process로 분산됨

SQL Trace는 상세 정보만큼 부하와 파일 크기도 증가시킵니다.

원칙
  → 전체 Database보다 특정 Session·업무
  → 긴 시간보다 재현 가능한 짧은 구간
  → Bind 수집은 기본적으로 비활성화
  → 활성화 명령과 비활성화 명령을 같은 절차에 기록

2. Trace 관리 조건

Oracle 공식 가이드는 SQL Trace 전에 다음 항목을 확인하도록 안내합니다.

ALTER SESSION SET tracefile_identifier = 'ORDER_SEARCH';

Trace를 Instance 전체에 적용하면 Process별 Trace 파일이 대량 생성될 수 있으므로 특별한 목적과 관리 절차가 없는 한 Session·업무 단위를 우선합니다.

3. Parse·Execute·Fetch Call

3.1 SELECT

Parse
  → 문법·권한·Object 확인
  → Shared Cursor 탐색·필요 시 Optimization

Execute
  → SELECT Cursor 실행 시작
  → 대상 Row를 식별할 준비

Fetch
  → Row Source에서 결과 생산
  → Array 단위로 Client에 반환
  → End-of-Fetch까지 반복

SELECT의 주요 Row 생산과 I/O가 Fetch에 나타나는 경우가 많습니다. 다만 Execute에서도 일부 작업이 발생할 수 있으므로 Plan·Driver·SQL 유형을 함께 봅니다.

3.2 DML

INSERT·UPDATE·DELETE·MERGE
  Parse
  → Execute에서 대상 Row 탐색·변경
  → Undo·Redo·Lock 작업
  → 일반적인 SELECT 결과 Fetch 없음

DML의 영향 Row 수는 Execute의 rows에 주로 표시됩니다.

3.3 Fetch Count 주의

Rows = 1,000
Array Fetch Size = 100
Fetch Call ≈ 10회 이상

실제 Fetch Count는 다음의 영향을 받습니다.

• Driver Array Fetch Size
• 마지막 End-of-Fetch Call
• Client의 일부 Fetch 후 Cursor Close
• LOB·Nested Cursor와 Driver 구현
• Parse·Execute·기타 Network Call

Fetch Count와 SQL*Net Round Trip은 관련이 있지만 같은 통계가 아닙니다.

4. 현재 Session Trace

현재 Session은 DBMS_SESSION.SESSION_TRACE_ENABLE을 사용할 수 있습니다.

ALTER SESSION SET tracefile_identifier = 'ORDER_SEARCH';

BEGIN
  DBMS_SESSION.SESSION_TRACE_ENABLE(
    waits     => TRUE,
    binds     => FALSE,
    plan_stat => 'FIRST_EXECUTION'
  );
END;
/

-- 문제 동작 재현

BEGIN
  DBMS_SESSION.SESSION_TRACE_DISABLE;
END;
/

DBMS_SESSION.SESSION_TRACE_DISABLE은 호출한 Session의 Session-level Trace만 해제합니다. Client ID 또는 Service·Module·Action으로 활성화한 Trace는 해당 DBMS_MONITOR Disable Procedure로 해제해야 합니다.

5. 다른 Session Trace

다른 Session을 Trace할 때는 SID와 SERIAL#을 함께 확인합니다.

SELECT inst_id,
       sid,
       serial#,
       username,
       service_name,
       module,
       action,
       client_identifier,
       sql_id
FROM   gv$session
WHERE  username = :username;

BEGIN
  DBMS_MONITOR.SESSION_TRACE_ENABLE(
    session_id => :sid,
    serial_num => :serial_no,
    waits      => TRUE,
    binds      => FALSE,
    plan_stat  => 'FIRST_EXECUTION'
  );
END;
/

BEGIN
  DBMS_MONITOR.SESSION_TRACE_DISABLE(
    session_id => :sid,
    serial_num => :serial_no
  );
END;
/

SESSION_TRACE_ENABLE은 호출자가 연결한 Local Instance의 Session을 대상으로 합니다. RAC에서 대상 Session이 어느 INST_ID에 있는지 확인하고 해당 Instance에서 실행합니다.

serial_num을 생략하면 같은 SID를 가진 Session을 Serial Number와 관계없이 대상으로 삼으므로 운영에서는 SID·SERIAL#을 함께 지정합니다.

6. Connection Pool과 End-to-End Trace

Connection Pool에서는 사용자 요청이 매번 같은 Database Session을 사용하지 않을 수 있습니다. SID 한 개만 Trace하면 다음 문제가 발생합니다.

• 같은 업무의 일부 요청을 놓침
• 같은 SID에서 다른 사용자 업무가 섞임
• 여러 Server Process·Instance에 Trace가 분산됨

Application은 다음 Context를 설정합니다.

SERVICE_NAME
MODULE
ACTION
CLIENT_IDENTIFIER

DBMS_APPLICATION_INFO.SET_MODULE, SET_ACTION 또는 Driver API, DBMS_SESSION.SET_IDENTIFIER를 사용할 수 있습니다.

Service·Module·Action Trace 예시는 다음과 같습니다.

BEGIN
  DBMS_MONITOR.SERV_MOD_ACT_TRACE_ENABLE(
    service_name  => 'ORDER_SVC',
    module_name   => 'ORDER_API',
    action_name   => 'SEARCH',
    waits         => TRUE,
    binds         => FALSE,
    instance_name => NULL,
    plan_stat     => 'FIRST_EXECUTION'
  );
END;
/

BEGIN
  DBMS_MONITOR.SERV_MOD_ACT_TRACE_DISABLE(
    service_name => 'ORDER_SVC',
    module_name  => 'ORDER_API',
    action_name  => 'SEARCH'
  );
END;
/

이 Trace는 기본적으로 Database 전역의 해당 Service·Module·Action 조합에 적용되며, instance_name으로 특정 Instance에 제한할 수 있습니다. 여러 Process가 업무를 처리하므로 여러 Trace 파일이 생성됩니다.

7. TRCSESS로 Trace 파일 병합

TRCSESS는 여러 Trace 파일에서 지정한 기준에 맞는 기록을 하나로 모읍니다.

지원 기준
  → session
  → clientid
  → service
  → module
  → action

Session은 SID.SERIAL# 형식으로 지정합니다.

trcsess output=order_search.trc \
  service=ORDER_SVC \
  module=ORDER_API \
  action=SEARCH \
  *.trc

Shared Server, Connection Pool, Service·Module·Action Trace에서는 한 업무의 정보가 여러 Process Trace에 나뉠 수 있으므로 병합 후 TKPROF를 수행합니다.

여러 Raw Trace
  → TRCSESS
  → 통합 Raw Trace
  → TKPROF

8. Trace 파일 위치 확인

ADR 환경에서는 V$DIAG_INFO를 사용할 수 있습니다.

SELECT name,
       value
FROM   v$diag_info
WHERE  name IN ('Diag Trace', 'Default Trace File');

Service·Module·Action 또는 Shared Server Trace는 여러 Process에 파일이 생성되므로 Trace Identifier, 문제 시간대, PDB·Instance와 업무 Context를 함께 기록합니다.

Oracle AI Database 26ai에서는 Container별 Trace 파일과 내용을 조회할 수 있는 V$DIAG_TRACE_FILE, V$DIAG_TRACE_FILE_CONTENTS도 제공합니다. 권한과 보안 정책을 따릅니다.

9. 10046 Level

전통적인 Extended SQL Trace Level은 다음과 같이 설명됩니다.

내부 Event 구문을 직접 설정하는 방식보다 DBMS_SESSION·DBMS_MONITOR의 waits, binds, plan_stat 옵션을 우선 사용하면 범위와 해제 절차가 명확합니다.

10. TKPROF 기본 사용

tkprof input.trc output.prf

대표 예시는 다음과 같습니다.

tkprof order_search.trc order_search.prf \
  waits=yes \
  sys=no \
  sort=exeela,fchela,prsela

AGGREGATE=NO가 모든 Execute Call을 완전히 개별 실행 단위로 분리해 준다고 단정하지 않습니다. 빠른 실행과 느린 실행의 시간 순서·Bind 차이는 Raw Trace에서 확인합니다.

11. TKPROF Call 통계

Logical I/O
  = query + current

rows는 SQL Statement의 Subquery 내부에서 처리한 모든 Row까지 포함하는 값이 아닙니다.

11.1 SELECT 예제

call     count      cpu    elapsed       disk      query    current       rows
------- ------  ------- ---------- ---------- ---------- ---------- ----------
Parse        1     0.01       0.02          0         20          0          0
Execute      1     0.00       0.01          0          2          0          0
Fetch       11     0.20       2.50        300      8,000          0      1,000
------- ------  ------- ---------- ---------- ---------- ---------- ----------
total       13     0.21       2.53        300      8,022          0      1,000

주요 작업
  → Fetch

Logical I/O
  → 8,022 Blocks

Fetch 비CPU 시간 단서
  → 2.50 - 0.20 = 2.30초

이 2.30초를 특정 Wait Event 하나로 바로 같다고 하지 않습니다. Trace Wait Records에서 I/O·Lock·Commit·Network·Scheduler 등 구성 요소를 확인합니다.

11.2 실행당·행당 계산

Execute Count = 100
Elapsed       = 50초
Query         = 1,000,000
Rows          = 20,000

Elapsed / Execution = 0.5초
Query / Execution   = 10,000 Blocks
Query / Row         = 50 Blocks

총량·실행당·행당 지표를 함께 봅니다.

12. Row Source Statistics와 Cursor Close

SQL Trace는 Cursor가 닫힐 때 실제 Row Source Statistics를 Trace에 기록할 수 있습니다.

Cursor Close
  → STAT Record 기록 가능
  → Actual Row Source Plan·Row Count 표시

다음 상황에서는 TKPROF에 Trace 당시 실제 Row Source Plan이 보이지 않을 수 있습니다.

• Cursor가 아직 열려 있음
• PL/SQL Cursor Cache에 Child Cursor가 유지됨
• Trace 종료 전에 Cursor Close가 발생하지 않음
• plan_stat='NEVER'
• 필요한 실행이 FIRST_EXECUTION 대상이 아니었음

SQL*Plus는 새 Statement 실행 시 이전 User Cursor를 닫는 경우가 많지만, PL/SQL Cursor 처리에서는 Parent가 닫혀도 Child Cursor가 바로 닫히지 않을 수 있습니다. 필요하면 업무 종료·Session 종료 또는 실제 Cursor Plan을 DISPLAY_CURSOR에서 교차 확인합니다.

13. TKPROF EXPLAIN Plan의 제한

TKPROF EXPLAIN=user/password는 Trace 당시 저장된 실제 Plan을 복원하는 기능이 아닙니다.

TKPROF 처리 시점
  → 지정 사용자로 Database 접속
  → EXPLAIN PLAN 새로 수행
  → 현재 통계·Schema·Parameter 기준 예상 Plan 출력

Trace 당시와 다음이 다르면 Plan이 달라질 수 있습니다.

• Bind 값과 Data Type
• Optimizer Parameter
• Object Statistics·Histogram
• Parsing Schema
• SQL Profile·Patch·Baseline
• Adaptive Final Plan
• Database Version

실제 Trace 당시 Plan은 Trace의 Row Source Statistics가 있으면 이를 우선하고, 현재 Cursor가 남아 있다면 DBMS_XPLAN.DISPLAY_CURSOR로 교차 확인합니다.

14. Recursive SQL과 COMMIT·ROLLBACK

SQL Trace Raw File에는 Commit·Rollback과 Recursive SQL 정보가 기록될 수 있습니다.

그러나 TKPROF는 Trace에 기록된 COMMIT과 ROLLBACK Statement를 보고하지 않습니다. Transaction 경계의 정확한 위치가 필요하면 Raw Trace를 확인합니다.

sys=no는 SYS·Recursive SQL을 보고서에서 제외해 User SQL에 집중할 수 있게 하지만 다음 원인을 놓칠 수 있습니다.

• Hard Parse와 Data Dictionary 접근
• Dynamic Sampling
• Space Management
• Recursive DDL·Internal SQL

Resource 총량을 계산할 때 User SQL과 그로 인해 발생한 Recursive SQL의 비용을 함께 고려할 수 있습니다.

15. Raw Trace가 필요한 경우

• 같은 SQL의 빠른·느린 실행이 집계 안에 섞임
• Bind 값별 실행 차이를 확인해야 함
• SQL Call·Commit·Rollback의 시간 순서가 필요함
• 특정 Wait가 Parse·Execute·Fetch 중 어디에서 발생했는지 확인
• Connection Pool 요청이 여러 Trace 파일에 분산됨
• Cursor가 닫히지 않아 TKPROF Plan이 누락됨
• TKPROF의 Aggregate 결과가 개별 Outlier를 숨김

TKPROF
  → SQL별 총량·평균·우선순위

Raw Trace
  → 개별 실행·시간 순서·Wait·Bind·Transaction Context

16. 보안·운영 위험

Bind Trace에는 고객번호, 계좌번호, 주민등록번호, Token 등 민감정보가 포함될 수 있습니다. Trace 파일은 운영 Data와 동일한 보안 수준으로 취급합니다.

17. 실전 분석 순서

1. 사용자·Service·Module·Action·시간 범위를 특정한다.
2. 필요한 최소 Trace 범위를 선택한다.
3. waits·binds·plan_stat와 보안·파일 제한을 결정한다.
4. Trace Identifier와 시작 시각을 기록한다.
5. 문제 동작을 재현한다.
6. 즉시 Trace를 해제하고 종료 시각을 기록한다.
7. 여러 파일이면 TRCSESS로 업무 단위 병합한다.
8. TKPROF에서 Total Elapsed·CPU·Disk·Query 기준 Top SQL을 찾는다.
9. Parse·Execute·Fetch 중 집중 Call을 찾는다.
10. 실행당·행당 I/O와 Time을 계산한다.
11. Wait Summary와 Raw Trace의 개별 Event를 연결한다.
12. Row Source Plan이 누락되면 Cursor Close·plan_stat 조건을 확인한다.
13. 빠른·느린 실행이 섞이면 Raw Trace에서 개별 실행·Bind를 비교한다.
14. 변경 후 같은 범위로 재수집해 Response Time과 작업량을 비교한다.

18. 자주 혼동하는 판단