fix(시세): LS spill-only·토큰 파일캐시·호가 snap_time 3초컷

- _feed_fallback 미러 OFF, LS cap/grace/hold RAM을 KIS·키움 spill과 정합
- LS 접근토큰 .ls_token_cache_*.json (재시작 재사용, revoke 루프 없음)
- 호가 RAM을 틱과 동일 LIVE_FEED_FALLBACK(snap_time)로 컷, 필터 max_age=0은 유지
- 익절 지정가 로그에 실제 호가 벤더(kis/kiwoom/ls 1·2·3차) 표기

Co-authored-by: Cursor <cursoragent@cursor.com>
This commit is contained in:
Your Name
2026-08-27 15:21:21 +09:00
parent ba2f9f0953
commit 5e44b86f8b
24 changed files with 1923 additions and 203 deletions

313
scripts/observe_ls_ws_journal.py Executable file
View File

@@ -0,0 +1,313 @@
#!/usr/bin/env python3
"""LS WS 저널 관측 — Bye / OPEN sends / abort_why / ws_same / RSP 집계.
장중(hold) 재현용. 장외에는 OPEN이 없어 요약이 비는 것이 정상.
사용:
python3 -u scripts/observe_ls_ws_journal.py --once
python3 -u scripts/observe_ls_ws_journal.py --watch --minutes 90
python3 -u scripts/observe_ls_ws_journal.py --since "2026-08-26 07:00:00"
출력:
logs/ls_ws_observe_YYYYMMDD_HHMMSS.log — 매칭 원문
logs/ls_ws_observe_YYYYMMDD_HHMMSS_summary.md — 집계
"""
from __future__ import annotations
import argparse
import os
import re
import subprocess
import sys
import time
from collections import Counter
from datetime import datetime, timedelta
from pathlib import Path
from typing import List, Optional, Tuple
ROOT = Path(__file__).resolve().parents[1]
LOG_DIR = ROOT / "logs"
SERVICE = "kis_trader_main.service"
# 관측 패치 + 8/25형 시그니처
PATTERNS = (
r"LS WS OPEN",
r"LS WS CLOSE",
r"LS WS ERROR",
r"LS WS RSP",
r"abort_why=",
r"ws_same=",
r"sends≈",
r"Bye",
r"opcode=8",
r"hold 외",
r"hold까지",
r"구독 복구",
r"US3|UH1",
r"ls_ws_ticks|ls_ws_orderbook",
r"LS WS 기동|LS_WS_ENABLED",
)
def _now_tag() -> str:
return datetime.now().strftime("%Y%m%d_%H%M%S")
def _default_since(explicit: Optional[str]) -> str:
if explicit:
return explicit.strip()
# 당일 00:00 (재시작·hold 전 구간 포함)
return datetime.now().strftime("%Y-%m-%d 00:00:00")
def _journal_lines(since: str, until: Optional[str] = None) -> List[str]:
cmd = [
"journalctl",
"-u",
SERVICE,
"--since",
since,
"--no-pager",
"-o",
"short-iso",
]
if until:
cmd.extend(["--until", until])
try:
p = subprocess.run(
cmd,
capture_output=True,
text=True,
timeout=180,
check=False,
)
except Exception as e:
return [f"[observe] journalctl 실패: {e}"]
if p.returncode not in (0, 1): # 1 = no entries
err = (p.stderr or "").strip()[:500]
return [f"[observe] journalctl rc={p.returncode} {err}"]
return (p.stdout or "").splitlines()
def _match_lines(lines: List[str]) -> List[str]:
rx = re.compile("|".join(f"(?:{p})" for p in PATTERNS), re.IGNORECASE)
return [ln for ln in lines if rx.search(ln)]
def _summarize(matched: List[str]) -> str:
sends = Counter()
abort = Counter()
ws_same = Counter()
rsp_cd = Counter()
n_open = n_close = n_bye = n_rsp = n_err = n_hold = 0
re_sends = re.compile(r"sends≈(\d+)")
re_abort = re.compile(r"abort_why=([^\s]+)")
re_ws = re.compile(r"ws_same=([^\s]+)")
re_rsp = re.compile(r"rsp_cd=([^\s]+)")
for ln in matched:
if "LS WS OPEN" in ln:
n_open += 1
m = re_sends.search(ln)
if m:
sends[m.group(1)] += 1
m = re_abort.search(ln)
if m:
abort[m.group(1)] += 1
if "LS WS CLOSE" in ln:
n_close += 1
m = re_ws.search(ln)
if m:
ws_same[m.group(1)] += 1
if "LS WS ERROR" in ln:
n_err += 1
m = re_ws.search(ln)
if m:
ws_same[f"err:{m.group(1)}"] += 1
if "LS WS RSP" in ln:
n_rsp += 1
m = re_rsp.search(ln)
if m:
rsp_cd[m.group(1)] += 1
if re.search(r"\bBye\b|opcode=8", ln, re.IGNORECASE):
n_bye += 1
if "hold 외" in ln or "hold까지" in ln:
n_hold += 1
def _top(c: Counter, n: int = 15) -> str:
if not c:
return "_없음_"
rows = [f"| `{k}` | {v} |" for k, v in c.most_common(n)]
return "\n".join(["| 값 | 건수 |", "|---|---:|"] + rows)
# 판정 힌트 (단정 금지 — 관측용)
hint = []
if n_open == 0 and n_hold > 0:
hint.append("OPEN 0 + hold 외 로그 → **장외 대기** (Bye 재현 구간 아님).")
if sends.get("1", 0) >= max(3, n_open // 2) and n_open >= 3:
hint.append(
f"OPEN 중 `sends≈1` 이 {sends.get('1', 0)}/{n_open}"
"8/25형 **불완전 REG** 의심 (JIF만 등)."
)
if n_bye >= 5 and n_open >= 3:
hint.append(f"Bye/opcode8 ≈{n_bye}, OPEN≈{n_open} → 연결 반복 끊김.")
if abort.get("opened_cleared", 0) > 0:
hint.append(
f"abort_why=opened_cleared ×{abort['opened_cleared']}"
"REG 중 `_opened` 클리어(stale close 가설) 점검."
)
if "False" in ws_same or "false" in {k.lower() for k in ws_same}:
hint.append("ws_same=False 존재 → CLOSE/ERROR 가 **다른/옛 소켓**일 수 있음.")
if not hint:
hint.append("특이 시그니처 부족 — 샘플·시간대 확인.")
ts = datetime.now().strftime("%Y-%m-%d %H:%M:%S")
return "\n".join(
[
f"# LS WS 저널 관측 요약",
f"",
f"- 생성: `{ts}`",
f"- 유닛: `{SERVICE}`",
f"- 매칭 줄 수: **{len(matched)}**",
f"",
f"## 카운트",
f"",
f"| 항목 | 건수 |",
f"|---|---:|",
f"| LS WS OPEN | {n_open} |",
f"| LS WS CLOSE | {n_close} |",
f"| Bye / opcode=8 | {n_bye} |",
f"| LS WS RSP | {n_rsp} |",
f"| LS WS ERROR | {n_err} |",
f"| hold 관련 | {n_hold} |",
f"",
f"## OPEN `sends≈N` 분포",
f"",
_top(sends),
f"",
f"## OPEN `abort_why`",
f"",
_top(abort),
f"",
f"## CLOSE/ERROR `ws_same`",
f"",
_top(ws_same),
f"",
f"## RSP `rsp_cd`",
f"",
_top(rsp_cd),
f"",
f"## 힌트 (가설, 단정 아님)",
f"",
*[f"- {h}" for h in hint],
f"",
f"## 다음 액션",
f"",
f"- `sends≈1` 다수 + Bye → REG 중단 원인 (`abort_why`, `ws_same`) 대조",
f"- RSP non-00000 → 서버 거절 메시지 확인",
f"- hold 외만 보이면 **07:00 이후** 재실행",
f"",
]
)
def _write_outputs(
matched: List[str],
summary_md: str,
tag: str,
) -> Tuple[Path, Path]:
LOG_DIR.mkdir(parents=True, exist_ok=True)
raw_path = LOG_DIR / f"ls_ws_observe_{tag}.log"
sum_path = LOG_DIR / f"ls_ws_observe_{tag}_summary.md"
raw_path.write_text("\n".join(matched) + ("\n" if matched else ""), encoding="utf-8")
sum_path.write_text(summary_md, encoding="utf-8")
return raw_path, sum_path
def run_once(since: str, until: Optional[str] = None) -> Tuple[Path, Path]:
lines = _journal_lines(since, until)
matched = _match_lines(lines)
tag = _now_tag()
summary = _summarize(matched)
summary = (
f"- since: `{since}`\n"
f"- until: `{until or 'now'}`\n"
f"- journal 총 줄: {len(lines)}\n\n"
+ summary
)
return _write_outputs(matched, summary, tag)
def run_watch(since0: str, minutes: float, interval_sec: float) -> Tuple[Path, Path]:
"""주기적으로 스냅샷을 덮어쓰지 않고 **최종 1회** since0~now 집계.
중간 진행은 stdout 에 OPEN/Bye 카운트만 찍음.
"""
end = time.time() + max(60.0, float(minutes) * 60.0)
iv = max(30.0, float(interval_sec))
print(
f"[observe] watch start since={since0!r} minutes={minutes} interval={iv}s",
flush=True,
)
while time.time() < end:
lines = _journal_lines(since0)
matched = _match_lines(lines)
n_open = sum(1 for ln in matched if "LS WS OPEN" in ln)
n_bye = sum(1 for ln in matched if re.search(r"\bBye\b|opcode=8", ln, re.I))
sends1 = sum(1 for ln in matched if re.search(r"sends≈1\b", ln))
print(
f"[observe] {datetime.now():%H:%M:%S} match={len(matched)} "
f"OPEN={n_open} sends≈1={sends1} Bye={n_bye}",
flush=True,
)
remain = end - time.time()
if remain <= 0:
break
time.sleep(min(iv, remain))
return run_once(since0)
def main() -> int:
ap = argparse.ArgumentParser(description="LS WS journal 관측")
ap.add_argument("--once", action="store_true", help="1회 집계 후 종료")
ap.add_argument(
"--watch",
action="store_true",
help="지정 분간 폴링 후 최종 집계 (cron 아침용)",
)
ap.add_argument("--minutes", type=float, default=90.0, help="--watch 지속(분)")
ap.add_argument("--interval", type=float, default=120.0, help="--watch 폴링 초")
ap.add_argument("--since", type=str, default="", help='journal --since (예: "2026-08-26 07:00:00")')
ap.add_argument("--until", type=str, default="", help="journal --until (선택)")
args = ap.parse_args()
since = _default_since(args.since or None)
until = (args.until or "").strip() or None
if args.watch:
# watch 시작 시각을 since 로 고정 (당일 hold 진입부터)
if not args.since:
# 오늘 07:00 (KR hold 기본). 이미 지났으면 07:00, 이전이면 since=지금-1h
today7 = datetime.now().replace(hour=7, minute=0, second=0, microsecond=0)
if datetime.now() < today7:
since = (datetime.now() - timedelta(hours=1)).strftime("%Y-%m-%d %H:%M:%S")
else:
since = today7.strftime("%Y-%m-%d %H:%M:%S")
raw, summ = run_watch(since, args.minutes, args.interval)
else:
raw, summ = run_once(since, until)
print(f"[observe] raw={raw}", flush=True)
print(f"[observe] summary={summ}", flush=True)
# 요약 앞부분 stdout
try:
text = summ.read_text(encoding="utf-8")
print(text[:2500], flush=True)
except Exception:
pass
return 0
if __name__ == "__main__":
sys.exit(main())

View File

@@ -0,0 +1,22 @@
#!/usr/bin/env bash
# LS WS 저널 관측 래퍼 — cron / 수동 공통
# 로그: logs/ls_ws_observe_cron_YYYYMMDD.log (래퍼 stdout)
set -euo pipefail
ROOT="$(cd "$(dirname "$0")/.." && pwd)"
cd "$ROOT"
mkdir -p logs
DAY="$(date +%Y%m%d)"
WRAPPER_LOG="logs/ls_ws_observe_cron_${DAY}.log"
MODE="${1:-watch}" # watch | once
shift || true
{
echo "======== $(date '+%F %T') start mode=${MODE} ========"
if [[ "$MODE" == "once" ]]; then
python3 -u scripts/observe_ls_ws_journal.py --once "$@"
else
# 기본: 07:00 hold 직후 90분 관측 (Bye/~1분 주기 포착)
python3 -u scripts/observe_ls_ws_journal.py --watch --minutes 90 --interval 120 "$@"
fi
echo "======== $(date '+%F %T') end ========"
} >>"$WRAPPER_LOG" 2>&1

View File

@@ -562,6 +562,8 @@ def run_validation() -> bool:
"WS_CANDLE_FREEZE_ON_CONFIRM",
"LIVE_FEED_FALLBACK_MAX_AGE_SEC",
"LS_FEED_FALLBACK_SUBSCRIBE",
"LS_WS_HOLD_RAM_KEEP_HOLDINGS",
"LS_WS_MAX_SUBSCRIPTIONS",
"LS_GAP_FILL_CANDIDATES",
"LS_WS_TICK_SAVE",
"LS_WS_ALSO_HOGA",
@@ -597,6 +599,8 @@ def run_validation() -> bool:
"PERM_LS_FILL_BARS",
"LIVE_FEED_FALLBACK_MAX_AGE_SEC",
"LS_FEED_FALLBACK_SUBSCRIBE",
"LS_WS_HOLD_RAM_KEEP_HOLDINGS",
"LS_WS_MAX_SUBSCRIPTIONS",
"LS_WS_TICK_SAVE",
"LS_WS_ALSO_HOGA",
"LS_WS_ORDERBOOK_SAVE",
@@ -742,19 +746,43 @@ def run_validation() -> bool:
else:
_성공("LS 3차 폴백 구독 _sync_feed_fallback_to_ls")
st_src = inspect.getsource(WSManager.sync_targets)
if "_sync_feed_fallback_to_ls" not in st_src or "_ls_ram_universe_codes" not in st_src:
실패목록.append("sync_targets LS RAM 합집합 없음")
_실패("sync_targets 가 _sync_feed_fallback_to_ls(_ls_ram_universe_codes) 를 안 부름")
else:
_성공("sync_targets 끝에서 LS RAM 합집합 구독 (MINIMAL OFF 경로)")
rec_src = inspect.getsource(WSManager._reconcile_split_subscriptions)
if "_sync_feed_fallback_to_ls" not in rec_src or "_ls_ram_universe_codes" not in rec_src:
실패목록.append("split reconcile LS RAM 합집합 없음")
_실패("_reconcile_split_subscriptions 가 LS RAM 합집합을 안 부름")
if "_finalize_ls_subscriptions" not in rec_src:
실패목록.append("split reconcile LS finalize 없음")
_실패("_reconcile_split_subscriptions 가 _finalize_ls_subscriptions 를 안 부름")
else:
_성공("split reconcile 도 LS RAM 합집합")
_성공("split reconcile → _finalize_ls_subscriptions (spill/permanent)")
if not hasattr(WSManager, "_prune_ls_ephemeral_subscriptions"):
실패목록.append("_prune_ls_ephemeral_subscriptions 없음")
_실패("LS spill grace 정리 헬퍼 없음")
else:
prune_src = inspect.getsource(WSManager._prune_ls_ephemeral_subscriptions)
if 'owner="spill"' not in prune_src:
실패목록.append("LS spill prune 없음")
_실패("_prune_ls_ephemeral_subscriptions 가 spill unsubscribe 안 함")
else:
_성공("LS spill/_feed_fallback ephemeral prune")
st_src = inspect.getsource(WSManager.sync_targets)
if "_finalize_ls_subscriptions" not in st_src:
실패목록.append("sync_targets LS finalize 없음")
_실패("sync_targets 가 _finalize_ls_subscriptions 를 안 부름")
else:
_성공("sync_targets 끝에서 LS finalize (MINIMAL OFF 경로)")
fb_src = inspect.getsource(WSManager._sync_feed_fallback_to_ls)
if 'LS_FEED_FALLBACK_SUBSCRIBE", False' in fb_src or "LS_FEED_FALLBACK_SUBSCRIBE', False" in fb_src:
_성공("LS_FEED_FALLBACK_SUBSCRIBE 코드 기본값=false (미러 OFF)")
else:
실패목록.append("LS_FEED_FALLBACK 기본 false 아님")
_실패("_sync_feed_fallback_to_ls get_env_bool 기본값이 false 가 아님")
db_fb = get_env_bool("LS_FEED_FALLBACK_SUBSCRIBE", False)
if db_fb:
print(
f" ⚠️ DB LS_FEED_FALLBACK_SUBSCRIBE=ON — 레거시 미러 활성. "
f"spill-only 운영 시 웹/DB에서 OFF 권장 (현재={_db원문('LS_FEED_FALLBACK_SUBSCRIBE')})"
)
start_src = inspect.getsource(WSManager.start)
if "kis_ws_ob = self.ws_cache" in start_src:
@@ -879,14 +907,55 @@ def run_validation() -> bool:
if not ps.should_persist_ls("005930", {"005930", "069500"}):
실패목록.append("should_persist_ls True 기대")
_실패("영구구독 코드인데 LS 적재 가드 False")
_실패("영구구독 코드인데 LS 봉/VI 가드 False")
else:
_성공("should_persist_ls: 영구구독 코드만 True")
_성공("should_persist_ls: 영구구독 코드만 True (봉·VI)")
if ps.should_persist_ls("999999", {"005930"}):
실패목록.append("should_persist_ls False 기대")
_실패("비영구 코드인데 LS 적재 허용")
_실패("비영구 코드인데 LS 봉/VI 적재 허용")
else:
_성공("should_persist_ls: 후보 spill 코드 False")
_성공("should_persist_ls: 후보 spill 코드 False (봉·VI)")
# 체결틱 DB 게이트 = 구독 전체 (_ls_is_subscribed), 영구만이 아님
try:
from pathlib import Path as _Path
_main_py = (_Path(__file__).resolve().parents[1] / "kis_trader" / "main.py").read_text(
encoding="utf-8", errors="replace",
)
except Exception:
_main_py = ""
if "LS_WS_TICK_SAVE" in _main_py and "_ls_is_subscribed(code)" in _main_py:
_성공("LS 체결틱 DB: 구독 전체(_ls_is_subscribed)")
elif "LS_WS_TICK_SAVE" in _main_py and "and self._ls_should_persist(code)" in _main_py:
실패목록.append("LS 틱이 영구게이트")
_실패("LS_WS_TICK_SAVE 가 _ls_should_persist(영구) — 구독전체여야 함")
else:
_주의("LS 틱 SAVE 게이트 패턴 확인 필요")
from kis_trader.engine.feed_fallback import merge_ls_ticks_third_fallback
_base = {
"005930": {
"202608191200": [
{"tick_time": "20260819120000", "source": "kis", "price": 1, "_lag_sec": 0},
]
}
}
_ls = {
"005930": {
"202608191200": [
{"tick_time": "20260819120000", "source": "ls", "price": 9, "_lag_sec": 0},
{"tick_time": "20260819120001", "source": "ls", "price": 8, "_lag_sec": 0},
]
}
}
_add = merge_ls_ticks_third_fallback(_base, _ls, max_lag_sec=3.0)
_sec0 = [t for t in _base["005930"]["202608191200"] if str(t.get("tick_time")) == "20260819120000"]
_sec1 = [t for t in _base["005930"]["202608191200"] if str(t.get("tick_time")) == "20260819120001"]
if _add != 1 or any(str(t.get("source")) == "ls" for t in _sec0) or not _sec1:
실패목록.append(f"LS 틱3차 merge 이상 add={_add}")
_실패(f"같은초 LS 중복/빈초 미채움: add={_add} sec0={_sec0} sec1={_sec1}")
else:
_성공("틱 3차 LS merge: 같은초 스킵·빈초만 채움")
if not hasattr(db, "insert_ls_ws_candle_if_absent"):
실패목록.append("insert_ls_ws_candle_if_absent 없음")
@@ -973,7 +1042,7 @@ def run_validation() -> bool:
)
_소스필수(
실패목록, LSWebSocketPriceCache._force_close_socket,
"_graceful_unreg_all", "LS 장양보 → UNREG",
"ram_keep_codes", "LS 장양보 → UNREG 후 RAM trim(영구·보유 pin)",
)
_소스필수(
실패목록, LSWebSocketPriceCache._send_raw,
@@ -1043,6 +1112,91 @@ def run_validation() -> bool:
f"| TICK_MAX_AGE={_db원문('WS_ORDERBOOK_TICK_MAX_AGE_SEC')}"
)
# 호가 snap_time = 틱 packet_lag 와 동일 LIVE_FEED_FALLBACK 컷
from datetime import datetime as _dt
from kis_trader.engine.feed_fallback import (
is_orderbook_snap_time_stale,
live_feed_fallback_max_age_sec,
)
from kis_trader.ws.orderbook_cache import OrderbookCache, OrderbookLevel, OrderbookSnapshot
_fb = float(live_feed_fallback_max_age_sec() or 3.0)
_fresh_st = _dt.now().strftime("%Y%m%d%H%M%S")
_stale_st = (_dt.now().replace(year=2020)).strftime("%Y%m%d") + "130248"
if _fb > 0:
if is_orderbook_snap_time_stale(_stale_st):
_성공(f"호가 snap_time 낡은 시각 → stale (LIVE_FEED_FALLBACK={_fb:g}s)")
else:
실패목록.append("orderbook snap_time stale 미검출")
_실패("호가 snap_time 낡음인데 is_orderbook_snap_time_stale=False")
if not is_orderbook_snap_time_stale(_fresh_st):
_성공("호가 snap_time 신선 → 통과")
else:
실패목록.append("orderbook snap_time fresh 오탐")
_실패("호가 snap_time 신선한데 stale 오탐")
if not is_orderbook_snap_time_stale(""):
_성공("호가 snap_time 빈값 → 버리지 않음(틱 lag None 과 동일)")
else:
실패목록.append("orderbook snap_time empty 오탐")
_실패("호가 snap_time 빈값인데 stale 오탐")
_obc = OrderbookCache()
# 강제로 매우 낡은 snap 주입 후 get(3) 거부·get(0) 유지 검증
_inj = OrderbookSnapshot(
code="375500",
bids=[OrderbookLevel(74000, 10)],
asks=[OrderbookLevel(74100, 10)],
total_bid_qty=10,
total_ask_qty=10,
ts=time.time(), # 수신 ts 는 신선
source="ls_uh1",
snap_time=_stale_st,
)
with _obc._lock:
_obc._data["375500"] = _inj
if _obc.get("375500", max_age_sec=3.0) is None:
_성공("호가 get(3s): ts 신선·snap 낡음 → None (체인 실패)")
else:
실패목록.append("orderbook get snap stale pass")
_실패("호가 get(3s) 가 snap 낡은데 통과")
if _obc.get("375500", max_age_sec=0.0) is not None:
_성공("호가 get(0)=마지막 RAM: snap 낡아도 반환 (FILTER 구멍 방지)")
else:
실패목록.append("orderbook get(0) snap reject")
_실패("호가 get(0) 이 snap 때문에 None — FILTER_MAX_AGE=0 위반")
# 신선한 LS 적재는 성공
_ok = _obc.update_from_ls_hoga(
"005930",
{
"offerho1": "70000", "bidho1": "69900",
"offerrem1": "5", "bidrem1": "5",
"hotime": _dt.now().strftime("%H%M%S"),
},
source="ls_uh1",
)
if _ok is not None and _obc.get("005930", max_age_sec=3.0) is not None:
_성공("호가 LS 신선 snap → RAM 적재·get(3s) OK")
else:
실패목록.append("orderbook fresh ls commit fail")
_실패("호가 신선 LS 적재/조회 실패")
# stale body: hotime 가 지금과 3초 초과면 skip (장중 130248 은 거의 항상 skip)
# 단위: 명시적 stale snap_time 주입 경로로 이미 get 검증함. ingest skip 은 helper 로.
_파일필수(
실패목록,
"kis_trader/ws/orderbook_cache.py",
"_commit_if_fresh",
"호가 RAM snap_time 컷(틱 skip_ram 정합)",
)
_파일필수(
실패목록,
"kis_trader/engine/feed_fallback.py",
"is_orderbook_snap_time_stale",
"호가 snap lag 헬퍼 = 틱 packet_lag",
)
else:
_주의("LIVE_FEED_FALLBACK=0 — 호가 snap_time 컷 OFF (레거시)")
_파일필수(
실패목록,
"kis_trader/backtest/param_search_optuna.py",