사고 개요

2026년 6월 9일, Lynceus v1.10.116 배포 후 /api/v1/system/orphan-positions 엔드포인트에서 간헐적 500 에러가 발생했다.

증상은 일관됐다. 이 엔드포인트를 호출할 때마다 500이 반환됐다. 로그를 보니:

TypeError: can't subtract offset-naive and offset-aware datetimes

Python datetime의 고전적 에러다. 그런데 이 에러가 새 배포 직전까지는 발생하지 않았다.


배경: Phase 124 timestamptz 전환

v1.10.116 이전, Phase 124에서 DB 스키마를 TIMESTAMP WITHOUT TIME ZONE에서 TIMESTAMP WITH TIME ZONE으로 전환했다.

이 전환으로 _cached_balance_at 같은 필드들이 이제 timezone-aware datetime을 저장하게 됐다.

# trading_engine.py — Phase 124 이후
self._cached_balance_at = now_kst_aware()  # aware datetime (KST)

DB에서 불러올 때도 aware datetime이 나온다. 모든 것이 aware로 통일된 것처럼 보였다.


문제 코드

그런데 조회 엔드포인트에 과거 코드가 남아 있었다.

# system.py — 버그 있는 코드
def get_orphan_positions():
    cached_at = self._cached_balance_at  # aware datetime (KST+09:00)
    
    # Phase 124 이전 습관: aware를 naive로 강제 변환 후 빼기
    _now = datetime.now(_KST).replace(tzinfo=None)  # naive로 만든다
    cache_age_sec = int((_now - cached_at).total_seconds())  # TypeError!
    
    # ...
    
    _now2 = datetime.now(_KST).replace(tzinfo=None)  # 또 naive
    cache_stale = (_now2 - cached_at).total_seconds() > 90  # 또 TypeError!

.replace(tzinfo=None)은 datetime 객체에서 timezone 정보를 제거한다. 변환이 아니라 삭제다.

결과: _now는 naive, cached_at은 aware. 둘을 빼면 Python이 거부한다.


왜 Phase 124 전까지는 괜찮았나

Phase 124 이전에는 _cached_balance_at이 naive datetime이었다.

# Phase 124 이전
self._cached_balance_at = datetime.now(_KST).replace(tzinfo=None)  # naive 저장

저장도 naive, 조회도 .replace(tzinfo=None)으로 naive → naive - naive는 정상 동작한다.

Phase 124에서 저장 측을 aware로 바꿨지만, 조회 측의 .replace(tzinfo=None)은 그대로 남았다. 마이그레이션의 절반만 이루어진 것이다.


TypeError가 모니터링을 통과한 이유

이 엔드포인트는 내부 관리용으로, 외부에서 자동으로 호출하는 health check나 주기적 폴링 대상이 아니었다.

Phase 124 배포 직후부터 orphan-positions는 깨져 있었지만:

  • 자동 테스트 커버리지가 없었다
  • 정기 모니터링 대상이 아니었다
  • Phase 134-01(weekly optimizer 수정) 작업 중 수동으로 호출해보다가 우연히 발견했다

중요 기능이 아닌 것처럼 보이는 엔드포인트도 테스트와 모니터링이 필요하다는 교훈이다.


수정

# 수정 전
_now = datetime.now(_KST).replace(tzinfo=None)
cache_age_sec = int((_now - cached_at).total_seconds())

_now2 = datetime.now(_KST).replace(tzinfo=None)
cache_stale = (_now2 - cached_at).total_seconds() > 90

# 수정 후
_now = datetime.now(_KST)  # aware 유지
cache_age_sec = int((_now - cached_at).total_seconds())

_now2 = datetime.now(_KST)  # aware 유지
cache_stale = (_now2 - cached_at).total_seconds() > 90

.replace(tzinfo=None) 두 줄을 제거했다. datetime.now(KST)는 이미 aware datetime을 반환하므로 추가 변환이 필요 없다.

aware - aware는 timedelta를 반환한다. 정상이다.


.replace(tzinfo=None)을 쓰는 이유와 올바른 대안

replace(tzinfo=None)을 쓰는 가장 흔한 이유는 naive datetime과 연산하기 위해서다.

# 잘못된 패턴: aware를 naive로 만들어서 naive와 연산
aware_dt = datetime.now(KST)
naive_dt = datetime(2026, 6, 9, 10, 0, 0)  # naive
diff = (aware_dt.replace(tzinfo=None) - naive_dt).total_seconds()  # 동작하지만 위험

이렇게 하면 동작은 하지만 timezone 정보가 사라지면서 KST와 UTC의 9시간 차이가 계산에서 무시된다.

올바른 방법은 naive datetime을 aware로 만드는 것이다.

from zoneinfo import ZoneInfo

KST = ZoneInfo("Asia/Seoul")

# 권장: naive를 aware로 만들어서 연산
naive_dt = datetime(2026, 6, 9, 10, 0, 0)
aware_dt = naive_dt.replace(tzinfo=KST)  # KST aware로 명시

now = datetime.now(KST)
diff = (now - aware_dt).total_seconds()

datetime 혼용을 막는 코드 리뷰 체크리스트

□ .replace(tzinfo=None) 사용 → 이유 있나? 대부분은 naive/aware 혼용 회피용 임시방편
□ datetime.now() (인자 없음) → datetime.now(KST)로 교체
□ datetime.utcnow() → 동일, KST aware로 교체  
□ datetime 빼기 연산 양쪽의 aware/naive 상태 확인
□ DB에서 불러온 datetime 필드가 aware인지 naive인지 확인

정리

항목내용
문제Phase 124 마이그레이션 후 orphan-positions 500 에러
원인저장 측은 aware로 전환했지만 조회 측 .replace(tzinfo=None) 미제거
에러TypeError: can't subtract offset-naive and offset-aware datetimes
해결.replace(tzinfo=None) 제거, datetime.now(KST) aware 그대로 사용
발견 지연 이유해당 엔드포인트 자동 호출 없음, 테스트 미존재
교훈마이그레이션은 저장/조회 양쪽을 동시에 처리해야 함. 내부 관리 엔드포인트도 테스트 필요