🔥 The Problem: When Your Checkpoint Won't Move

아침에 일어나서 Oracle GoldenGate 복제가 몇 시간씩 지연되고 있는 것을 발견한 적이 있나요? 그런데 모든 것이 "정상"으로 보인다면?

최근 프로덕션 환경에서 Extract 프로세스가 3.5시간의 checkpoint lag를 보이면서도 실제 데이터 캡처(GETLAG)는 단 1초였던 이상한 문제를 해결했습니다.

-- 모든 Extract 프로세스 상태 확인
GGSCI> info all

Program     Status      Group       Lag at Chkpt  Time Since Chkpt
EXTRACT     RUNNING     01CD086E    03:30:00      00:00:00
EXTRACT     RUNNING     01CS087E    03:30:00      00:00:00
EXTRACT     RUNNING     01MD088E    03:30:00      00:00:00
EXTRACT     RUNNING     01SD085E    03:30:00      00:00:00
EXTRACT     RUNNING     01SS084E    03:30:00      00:00:00

하지만 여기서 이상한 점이 있었습니다. GETLAG를 확인했을 때:

GGSCI> SEND EXTRACT 01SS084E, GETLAG
Sending GETLAG request to EXTRACT 01SS084E ...
Last record lag 1 seconds.

🔍 The Investigation: Finding the Culprit

GGSCI> SEND EXTRACT 01SS084E, SHOWTRANS DURATION 240 MIN

------------------------------------------------------------
XID:         14.15.4795600
Items:       0
Extract:     01SS084E
Redo Thread: 1
Start Time:  2025-08-10:04:12:58
SCN:         1.4038799620 (8333766916)
Redo Seq:    74849
Redo RBA:    42582120
Status:      Running

GGSCI> SEND EXTRACT 01CD086E, SHOWTRANS DURATION 240 MIN
GGSCI> SEND EXTRACT 01CS087E, SHOWTRANS DURATION 240 MIN
GGSCI> SEND EXTRACT 01MD088E, SHOWTRANS DURATION 240 MIN
GGSCI> SEND EXTRACT 01SD085E, SHOWTRANS DURATION 240 MIN
GGSCI> SEND EXTRACT 01SS084E, SHOWTRANS DURATION 240 MIN

SQL> SELECT * FROM v$transaction 
WHERE xidusn=14 AND xidslot=15 AND xidsqn=4795600;

no rows selected

SELECT sample_time, session_id, session_serial#, sql_id, sql_opname,
       program, module, machine, event
FROM dba_hist_active_sess_history
WHERE xid = hextoraw('000E000F00492CD0')  -- XID를 RAW 형식으로 변환
AND sample_time BETWEEN 
    TO_TIMESTAMP_TZ('2025-08-10 03:45:00 +01:00','YYYY-MM-DD HH24:MI:SS TZH:TZM')
    AND TO_TIMESTAMP_TZ('2025-08-10 05:15:00 +01:00','YYYY-MM-DD HH24:MI:SS TZH:TZM')
ORDER BY sample_time;

💡 The Root Cause: Index Rebuild Operations

4:12 AM 타임스탬프를 기억하시나요? 우리는 4:00 AM에 인덱스 리빌드 작업을 시작했었습니다:

ALTER INDEX BAPCO_MDB.CORERELATIONORIGINOIDN 
    REBUILD ONLINE NOLOGGING PARALLEL 14;
    
ALTER INDEX BAPCO_MDB.CORERELATIONORIGINTYPEN 
    REBUILD ONLINE NOLOGGING PARALLEL 14;

✅ The Solution: Controlled Extract Restart

SELECT sequence#, name, first_time, next_time
FROM v$archived_log
WHERE thread# = 1 AND sequence# >= 74849
ORDER BY sequence#;

GGSCI> SEND EXTRACT 01CD086E, FORCESTOP
Sending FORCESTOP request to EXTRACT 01CD086E ...
Request processed.

-- 10-20초 대기

GGSCI> START EXTRACT 01CD086E
Sending START request to MANAGER ('GGSMGR_S3D') ...
EXTRACT 01CD086E starting

GGSCI> SEND EXTRACT 01CD086E, STATUS

EXTRACT 01CD086E (PID 12164)
Current status: In recovery[1]: Processing data
Current read position:
Redo thread #: 1
Sequence #: 74851
RBA: 271748752
Timestamp: 2025-08-10 04:13:26.000000

GGSCI> SEND EXTRACT 01CD086E, SHOWTRANS DURATION 240 MIN
No transactions found.

GGSCI> INFO EXTRACT 01CD086E
Checkpoint Lag       00:00:02 (updated 00:00:01 ago)

📊 Key Monitoring Commands

이 문제를 해결하는 동안 다음 명령어들이 매우 유용했습니다:

# Transaction 상태 확인
SEND EXTRACT <group_name>, SHOWTRANS DURATION 240 MIN

# 현재 lag 확인
SEND EXTRACT <group_name>, GETLAG

# 상세 상태 확인
SEND EXTRACT <group_name>, STATUS

# 통계 보기
STATS EXTRACT <group_name> LATEST

# Lag 정보
LAG EXTRACT <group_name>

# 상세 정보
INFO EXTRACT <group_name>, DETAIL

🛡️ Prevention Tips

이 문제를 해결한 후, 향후 재발 방지를 위해 다음과 같은 조치를 구현했습니다:

• Off-Peak 시간에 인덱스 리빌드 수행: 트랜잭션 활동이 최소인 시간대로 유지보수 작업 이동
• Parallel Degree 감소: PARALLEL 14 대신 PARALLEL 4-8 사용. 병렬 처리 감소로 트랜잭션 시간 단축
• NOLOGGING 대신 LOGGING 사용: 데이터베이스 레벨에서 FORCE_LOGGING=YES여도 DDL에서 명시적으로 LOGGING 지정
• 사전 모니터링 설정: Checkpoint lag가 30분을 초과하면서 GETLAG가 낮을 때 알림 설정
• 파티션 레벨 작업 고려: 파티션 테이블의 경우 전체 인덱스보다 파티션 레벨에서 리빌드

🎯 The Bottom Line

기억해야 할 사항:

• FORCESTOP 전에 항상 archive log 가용성 확인
• Extract 프로세스를 동시에 모두 재시작하지 말고 하나씩 순차적으로 재시작
• Recovery 진행 상황을 모니터링하고 완료까지 충분한 시간 허용
• 문제 패턴을 문서화하여 향후 빠른 해결 도모