#!/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())