증상

lynceus-lite 스톱로스 시스템을 VTS(모의 투자 환경)에서 e2e 검증하던 중 이상한 패턴을 발견했다.

신규 포지션을 진입한 직후 스케줄러 첫 사이클에서는 해당 종목의 실시간 시세가 오지 않았다. 두 번째 사이클부터 정상적으로 WebSocket 시세가 들어왔다. 에러 로그는 없었다. 두 번째 사이클에서는 아무 코드 변경 없이 스스로 정상화됐다.

정확히 1사이클 지연이었다. 그리고 그 1사이클 동안 시세가 없으면 스톱로스 판단이 내려지지 않는다.

lynceus-lite에서 스케줄러 사이클은 수십 초 단위다. 변동성이 큰 종목을 새로 매수한 직후, 첫 사이클에서 스톱로스 엔진이 실시간 가격 없이 동작한다는 뜻이다. REST 폴백이 있어 완전한 무방비 상태는 아니지만, 설계 의도와 다르고 신뢰할 수 없다.

처음에는 WebSocket 연결 문제를 의심했다. 연결 자체는 정상이었다. WS 서비스가 구독 요청을 받지 못한 것이었다.

스케줄러 구조

run_stoploss_cycle()은 일정 주기마다 실행되는 핵심 사이클 함수다. 단순화하면 다음 순서로 동작한다.

async def run_stoploss_cycle() -> None:
    async with get_session() as session:
        # 1. 활성 사용자 목록 로드
        active_keys = await _load_active_user_envs(session)

        # 2. (구버전) WS 구독 동기화 ← 여기서 문제 발생
        await _sync_quote_context(session, active_keys)

        # 3. 각 사용자별 처리
        for user_id, env in active_keys:
            # holdings 동기화 (KIS 브로커 → 로컬 DB)
            await HoldingsKISAdapter(base, session).sync_to_positions(user_id, env)
            # 스톱로스 엔진 실행
            result = await engine.run_cycle(user_id, env, effective_mode)
            # 알림 처리
            await run_notification_stage(...)

_load_active_user_envs는 활성화된 사용자와 환경(paper/live) 목록을 반환한다. 실제 포지션 데이터는 이 함수가 아니라 for 루프 안의 HoldingsKISAdapter.sync_to_positions()가 브로커에서 가져와 로컬 DB에 반영한다.

원인

_sync_quote_context는 로컬 DB의 포지션 목록을 읽어 WebSocket 구독 목록을 구성한다.

async def _sync_quote_context(
    session: AsyncSession,
    active_keys: list[tuple[int, str]],
) -> None:
    """열린 포지션으로 WS 구독과 즉시 반응 임계를 갱신한다."""
    quote_hub.clear_watches()
    desired: dict[str, set[str]] = {"paper": set(), "live": set()}
    # DB에서 현재 포지션 조회 → 구독 목록 구성
    ...
    for env, tickers in desired.items():
        await ws_service.sync_subscriptions(env, tickers)

문제는 타이밍이다.

사용자가 신규 종목을 매수하면, 해당 포지션은 KIS 브로커에 즉시 반영된다. 하지만 로컬 DB에는 아직 없다. 로컬 DB 반영은 스케줄러 사이클의 sync_to_positions() 호출이 일어나야 한다.

[사용자 매수 체결]
        ↓
[KIS 브로커: 신규 포지션 존재]
        ↓
[사이클 N 시작]
  ├─ _sync_quote_context() 실행 (구버전 위치)
  │      ↓
  │    로컬 DB 조회 → 신규 포지션 없음 → WS 구독 목록에 미포함
  │
  └─ for 루프 실행
       ↓
     sync_to_positions() → 신규 포지션 로컬 DB 반영
[사이클 N 종료]
        ↓
[사이클 N+1 시작]
  ├─ _sync_quote_context() 실행
  │      ↓
  │    로컬 DB 조회 → 신규 포지션 발견 → WS 구독 추가
  ...

_sync_quote_context가 sync_to_positions() 보다 앞에서 실행되기 때문에, 신규 매수 직후 첫 사이클에서는 로컬 DB가 아직 갱신되지 않은 상태에서 구독 목록이 확정된다. 실제 구독은 다음 사이클에서야 이루어진다.

에러가 없고, 두 번째 사이클부터는 정상인 이유가 여기 있다. 코드 자체는 올바르게 동작했지만, 실행 순서가 의도와 달랐다.

수정

고치는 방법은 단순하다. _sync_quote_context 호출을 for 루프 이후로 옮긴다.

async def run_stoploss_cycle() -> None:
    async with get_session() as session:
        active_keys = await _load_active_user_envs(session)

        # for 루프 먼저: 각 사용자 holdings 동기화 포함
        for user_id, env in active_keys:
            await HoldingsKISAdapter(base, session).sync_to_positions(user_id, env)
            result = await engine.run_cycle(user_id, env, effective_mode)
            await run_notification_stage(...)

        # holdings 동기화가 끝난 후 WS 구독 목록 갱신
        try:
            await _sync_quote_context(session, active_keys)
        except Exception:
            logger.warning("quote_ws_context_sync_failed", exc_info=True)
            await session.rollback()

        health.note_degraded_if_needed()

이 순서에서는 for 루프가 완료된 시점에 모든 사용자의 최신 포지션이 로컬 DB에 반영되어 있다. 그 후 _sync_quote_context가 실행되므로 신규 포지션도 같은 사이클에서 WS 구독 목록에 포함된다.

[사용자 매수 체결]
        ↓
[사이클 N 시작]
  └─ for 루프 실행
       ↓
     sync_to_positions() → 신규 포지션 로컬 DB 반영
       ↓
  _sync_quote_context() 실행 (수정 후 위치)
       ↓
  로컬 DB 조회 → 신규 포지션 발견 → WS 구독 추가
[사이클 N에서 즉시 구독 완료]

수정 전후 diff는 실제로 7줄이다. 이동한 코드 블록을 제외하면 변경된 로직은 없다.

왜 눈에 띄지 않았나

이런 타이밍 버그가 처음부터 발견되지 않은 이유가 있다.

첫째, 증상이 조용하다. 1사이클 지연이 발생해도 에러가 없다. 두 번째 사이클부터 정상 동작하므로 로그만 보면 아무 문제가 없는 것처럼 보인다.

둘째, 타이밍이 맞아야 재현된다. 신규 포지션 진입 직후 스케줄러 사이클이 돌아야 한다. 매수 직후 몇 초 이내에 사이클이 실행되지 않으면 이미 다음 사이클에서 포지션이 정상 반영되어 문제가 보이지 않는다.

셋째, 단위 테스트가 이 시나리오를 커버하지 않았다. 기존 테스트는 이미 DB에 포지션이 있는 상태를 가정했다. “포지션이 이번 사이클의 holdings sync 중 처음 반영되는” 상황을 테스트하는 케이스가 없었다.

VTS e2e 환경에서 실제 매수 후 시세를 모니터링했기 때문에 발견할 수 있었다.

회귀 가드 테스트

수정 후 이 결함이 재발하지 않도록 통합 테스트를 추가했다.

@pytest.mark.asyncio
async def test_cycle_syncs_new_holding_to_quote_context_before_return(
    async_session: AsyncSession,
    monkeypatch: pytest.MonkeyPatch,
) -> None:
    """신규 포지션이 holdings sync 이후 같은 사이클에서 WS 구독에 반영되는지 검증한다."""
    # WS 서비스 mock: sync_subscriptions 호출 기록
    ws_service = _QuoteWSService()

    # 신규 포지션이 holdings sync 후 DB에 추가되는 상황 시뮬레이션
    new_ticker = "005930"  # 삼성전자

    # _sync_quote_context가 for 루프 이후 실행되어야
    # new_ticker가 desired 구독 집합에 포함됨을 단언
    await scheduler.run_stoploss_cycle()

    assert new_ticker in ws_service.desired.get("live", set()), (
        "신규 포지션 종목이 같은 사이클에서 WS 구독에 포함되어야 한다"
    )

이 테스트는 _sync_quote_context가 for 루프 이후에 실행되어야만 통과한다. 누군가 다시 순서를 뒤집는 코드를 작성하면 이 테스트가 잡아준다.

핵심 교훈

구독 동기화는 데이터 소스 갱신 이후에 실행해야 한다.

이 사례에서 데이터 소스는 로컬 DB의 포지션 테이블이고, 갱신 주체는 sync_to_positions()다. _sync_quote_context는 이 데이터를 읽는 소비자다. 소비자가 생산자보다 먼저 실행되면, 생산자가 아직 만들지 않은 데이터를 읽게 된다.

같은 패턴이 다른 맥락에서도 나타난다.

  • 캐시를 채우기 전에 캐시를 읽는 코드
  • DB에 커밋되기 전에 해당 데이터를 기반으로 알림을 보내는 코드
  • 파일이 닫히기 전에 해당 파일 내용을 처리하는 코드

공통점은 데이터 흐름의 의존 관계를 코드 실행 순서가 반영하지 못한다는 것이다. 에러가 없기 때문에 즉시 발견되지 않고, 타이밍이 맞아야 재현되기 때문에 간헐적으로 나타난다.

정리

항목구버전수정 후
_sync_quote_context 위치sync_to_positions() 이전sync_to_positions() 이후
신규 포지션 WS 구독 타이밍N+1 사이클동일 사이클 (N)
에러 로그없음없음
발견 방법VTS e2e 모니터링—
재발 방지—통합 테스트 추가

1사이클 지연은 작아 보인다. 하지만 스톱로스 시스템에서 1사이클은 수십 초일 수 있다. 그 시간 동안 실시간 시세 없이 가격 판단을 내릴 수 없다. 순서 하나가 만드는 결함은 종종 이처럼 조용하고 간헐적이어서, 단위 테스트보다 실제 흐름을 관찰하는 e2e 검증이 더 먼저 잡아낸다.