#!/usr/bin/env python3 # -*- coding: utf-8 -*- """ kis_error_watch_mm.py — kis_trader_main journalctl 실시간(tail -f) 감시 → Mattermost 실매 봇과 분리된 프로세스. journald 만 보고 오류 시 MM 알림. - Traceback / FATAL / dead=[...] / 유닛 다운 등 - 동일·유사 알림은 쿨다운으로 스팸 방지 - 상태 JSON 즉시 저장(재시작 후에도 쿨다운 유지) 실행: nohup .venv/bin/python -u scripts/kis_error_watch_mm.py \\ >> logs/kis_error_watch_mm.log 2>&1 & tail -f logs/kis_error_watch_mm.log 테스트: .venv/bin/python scripts/kis_error_watch_mm.py --test-mm systemd (선택): sudo cp deploy/kis_error_watch_mm.service /etc/systemd/system/ sudo systemctl daemon-reload && sudo systemctl enable --now kis_error_watch_mm """ from __future__ import annotations import argparse import hashlib import logging import os import re import signal import subprocess import sys import time from datetime import datetime from pathlib import Path from typing import List, Optional, Pattern, Tuple ROOT = Path(__file__).resolve().parents[1] sys.path.insert(0, str(ROOT)) from kis_trader.utils.env import ( # noqa: E402 get_env_bool, get_env_float, get_env_from_db, get_env_int, ) from kis_trader.utils.logger import atomic_load_json, atomic_save_json, msg_mm # noqa: E402 LOG_PATH = ROOT / "logs" / "kis_error_watch_mm.log" STATE_PATH = ROOT / "logs" / "kis_error_watch_mm_state.json" LOG_PATH.parent.mkdir(parents=True, exist_ok=True) logging.basicConfig( level=logging.INFO, format="[%(asctime)s] %(message)s", datefmt="%H:%M:%S", handlers=[logging.StreamHandler(sys.stdout)], ) log = logging.getLogger("error_watch") _STOP = False def _on_signal(signum, _frame) -> None: global _STOP _STOP = True log.info("⏹ signal=%s → 종료 예약", signum) def _cfg() -> dict: """DB/env 설정 — 하드코딩 수치 금지, get_env_* 만.""" # Traceback·FATAL·비어있지 않은 dead=·유닛 크래시 시그니처 default_match = ( r"(?i)(" r"Traceback \(most recent call last\)|" r"\bCRITICAL\b|\bFATAL\b|MemoryError|SIGBUS|Segmentation fault|" r"dead=\[[^\]]|" # dead=[] 제외, dead=['Strat-... 매칭 r"Main process exited|Failed with result|" r"can't open file|" r"강제\s*종료|Out of memory" r")" ) default_ignore = ( r"(?i)(" r"numexpr\.utils|" r"\[MM 스킵\]|" r"MM 발송 실패|" r"heartbeat ws=" r")" ) return { "enabled": get_env_bool("ERROR_WATCH_ENABLED", True), "unit": str( get_env_from_db("ERROR_WATCH_UNIT", "kis_trader_main.service") or "kis_trader_main.service" ).strip(), "channel": str( get_env_from_db("ERROR_WATCH_MM_CHANNEL", "") or get_env_from_db("KIS_SYSTEM_MM_CHANNEL", "default") or "default" ).strip() or "default", "cooldown_sec": max(30, get_env_int("ERROR_WATCH_COOLDOWN_SEC", 180)), "context_lines": max(1, min(20, get_env_int("ERROR_WATCH_CONTEXT_LINES", 5))), "traceback_extra": max(0, min(40, get_env_int("ERROR_WATCH_TRACEBACK_EXTRA_LINES", 12))), "health_sec": max(15, get_env_int("ERROR_WATCH_HEALTH_CHECK_SEC", 60)), "match_re": str( get_env_from_db("ERROR_WATCH_MATCH_REGEX", default_match) or default_match ), "ignore_re": str( get_env_from_db("ERROR_WATCH_IGNORE_REGEX", default_ignore) or default_ignore ), "jitter": get_env_bool("ERROR_WATCH_MM_JITTER", False), } def _compile_re(pat: str, name: str) -> Optional[Pattern[str]]: try: return re.compile(pat) except re.error as e: log.error("❌ regex 컴파일 실패 (%s): %s", name, e) return None def _load_state() -> dict: st = atomic_load_json(STATE_PATH, default={}) if not isinstance(st, dict): return {} return st def _save_state(st: dict) -> None: atomic_save_json(STATE_PATH, st) def _fp(text: str) -> str: # 시각·PID 제거 후 지문 → 같은 오류 반복 쿨다운 norm = re.sub(r"\d{2}:\d{2}:\d{2}", "", text) norm = re.sub(r"python\[\d+\]", "python[PID]", norm) norm = re.sub(r"\s+", " ", norm).strip()[:800] return hashlib.sha1(norm.encode("utf-8", errors="ignore")).hexdigest()[:16] def _can_alert(st: dict, fingerprint: str, cooldown_sec: int) -> bool: now = time.time() last_ts = float(st.get("last_alert_ts") or 0) last_fp = str(st.get("last_fingerprint") or "") if fingerprint == last_fp and (now - last_ts) < cooldown_sec: return False if (now - last_ts) < float(get_env_float("ERROR_WATCH_GLOBAL_MIN_GAP_SEC", 20.0)): # 서로 다른 오류라도 최소 간격 if fingerprint != last_fp and (now - last_ts) < cooldown_sec * 0.15: return False return True def _send_alert(title: str, lines: List[str], channel: str, jitter: bool, st: dict, fingerprint: str) -> bool: body_lines = [ f"🚨 **[오류감시] {title}**", f"- 시각: {datetime.now().strftime('%Y-%m-%d %H:%M:%S')}", f"- 유닛: `{get_env_from_db('ERROR_WATCH_UNIT', 'kis_trader_main.service')}`", "```", ] clipped = "\n".join(lines)[:3500] body_lines.append(clipped) body_lines.append("```") body = "\n".join(body_lines) ok = msg_mm(body, channel_alias=channel, jitter=jitter) st["last_alert_ts"] = time.time() st["last_fingerprint"] = fingerprint st["last_title"] = title st["alert_count"] = int(st.get("alert_count") or 0) + 1 _save_state(st) log.info("📤 MM %s title=%s fp=%s", "OK" if ok else "FAIL", title, fingerprint) return ok def _unit_active(unit: str) -> Tuple[bool, str]: try: r = subprocess.run( ["systemctl", "is-active", unit], capture_output=True, text=True, timeout=5, ) state = (r.stdout or "").strip() or (r.stderr or "").strip() or "unknown" return state == "active", state except Exception as e: return False, f"check_error:{e}" def _follow_journal(unit: str) -> subprocess.Popen: # -n 0: 과거 덤프 없이 follow만 (기동 직후 과거 Traceback 폭주 방지) cmd = [ "journalctl", "-u", unit, "-f", "-n", "0", "--output=short-iso", "--no-pager", ] log.info("📡 follow: %s", " ".join(cmd)) return subprocess.Popen( cmd, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, text=True, bufsize=1, errors="replace", ) def run_watch() -> int: cfg = _cfg() if not cfg["enabled"]: log.warning("ERROR_WATCH_ENABLED=false → 종료") return 0 match_re = _compile_re(cfg["match_re"], "MATCH") ignore_re = _compile_re(cfg["ignore_re"], "IGNORE") if match_re is None: return 2 unit = cfg["unit"] channel = cfg["channel"] st = _load_state() log.info( "✅ 감시 시작 unit=%s ch=%s cooldown=%ss health=%ss", unit, channel, cfg["cooldown_sec"], cfg["health_sec"], ) # 기동 알림 (감시자 살아있음 확인) if get_env_bool("ERROR_WATCH_STARTUP_NOTIFY", True): active, state = _unit_active(unit) msg_mm( f"👁️ **[오류감시 기동]** `{unit}` → `{state}`" f"{' ✅' if active else ' ⚠️ 비활성'}", channel_alias=channel, jitter=False, ) proc = _follow_journal(unit) buf: List[str] = [] collecting_tb = False tb_left = 0 last_health = time.time() was_active = True assert proc.stdout is not None while not _STOP: # health poll now = time.time() if now - last_health >= cfg["health_sec"]: last_health = now active, state = _unit_active(unit) if not active: fp = _fp(f"unit_down:{unit}:{state}") if _can_alert(st, fp, cfg["cooldown_sec"]): _send_alert( f"유닛 비활성 ({state})", [f"systemctl is-active {unit} → {state}"], channel, cfg["jitter"], st, fp, ) was_active = False elif not was_active: # 복구 알림 fp = _fp(f"unit_up:{unit}") if _can_alert(st, fp, max(30, cfg["cooldown_sec"] // 3)): _send_alert( "유닛 복구 (active)", [f"systemctl is-active {unit} → active"], channel, cfg["jitter"], st, fp, ) was_active = True # journalctl 죽었으면 재기동 if proc.poll() is not None: log.warning("⚠️ journalctl 종료 code=%s → 재기동", proc.returncode) proc = _follow_journal(unit) assert proc.stdout is not None # non-blocking-ish read with timeout via select import select ready, _, _ = select.select([proc.stdout], [], [], 1.0) if not ready: continue line = proc.stdout.readline() if line == "": # EOF — 재기동 time.sleep(1.0) if proc.poll() is not None: proc = _follow_journal(unit) assert proc.stdout is not None continue line = line.rstrip("\n") if not line: continue # ignore if ignore_re is not None and ignore_re.search(line): continue # Traceback 블록 수집 if "Traceback (most recent call last)" in line: collecting_tb = True tb_left = cfg["traceback_extra"] buf = [line] continue if collecting_tb: buf.append(line) tb_left -= 1 # 들여쓴 프레임이 끝나고 일반 로그가 오면 종료 if tb_left <= 0 or ( len(buf) > 2 and not line.startswith(" ") and not line.startswith("\t") and "File \"" not in line and not line.lstrip().startswith("File ") and "Error" not in line and "Exception" not in line ): collecting_tb = False block = buf[:] buf = [] fp = _fp("\n".join(block)) if _can_alert(st, fp, cfg["cooldown_sec"]): _send_alert("Traceback", block, channel, cfg["jitter"], st, fp) continue if match_re.search(line): # 직전 컨텍스트는 journal에 없으므로 히트 라인 + 이후 N줄은 어려움 → 히트만 ctx = [line] fp = _fp(line) if _can_alert(st, fp, cfg["cooldown_sec"]): title = "로그 오류 매칭" if "dead=[" in line: title = "전략 dead 감지" elif "exited" in line.lower() or "Failed with result" in line: title = "프로세스 종료" _send_alert(title, ctx, channel, cfg["jitter"], st, fp) try: proc.terminate() except Exception: pass log.info("👋 오류감시 종료") return 0 def run_test_mm() -> int: ch = str( get_env_from_db("ERROR_WATCH_MM_CHANNEL", "") or get_env_from_db("KIS_SYSTEM_MM_CHANNEL", "default") or "default" ).strip() or "default" ok = msg_mm( "🧪 **[오류감시 테스트]** kis_error_watch_mm.py --test-mm OK", channel_alias=ch, jitter=False, ) print(f"test_mm channel={ch} ok={ok}") return 0 if ok else 1 def main() -> int: signal.signal(signal.SIGINT, _on_signal) signal.signal(signal.SIGTERM, _on_signal) ap = argparse.ArgumentParser(description="kis_trader journal 오류 → Mattermost") ap.add_argument("--test-mm", action="` `", help="테스트 메시지 1회 발송 후 종료") args = ap.parse_args() if args.test_mm: return run_test_mm() return run_watch() if __name__ == "__main__": raise SystemExit(main())