""" 옵투나·백테 피드 추적 로그 — 실매 TRIGGER_FEED_DETAIL 과 같은 축. 무엇을 보나: - 틱/호가 DB 로드 후 벤더(kis|kiwoom|ls|…) 건수·비율 - 설정 1·2·3차 체인 (실매 live_*_primary 와 동일) - (옵션) 매수 후보 샘플: px·틱타임·호가 bid/ask·entry_source 실매 `_scan_log` 꼬리와 문구를 맞춰, 옵투나 로그만 봐도 “어느 벤더로 체결·호가판정했는지” 추적 가능. """ from __future__ import annotations from collections import Counter from typing import Any, Dict, List, Optional, Tuple from kis_trader.utils.env import get_env_bool, get_env_int from kis_trader.utils.logger import get_logger logger = get_logger("kis_trader.optuna_feed_trace") # 프로세스당 샘플 상한 (옵투나 trial×종목 폭주 방지) _sample_logged = 0 _pp_sample_logged = 0 def bt_feed_detail_enabled() -> bool: """옵투나 TRIGGER 샘플 ON/OFF (벤더 비율 INFO는 항상).""" return get_env_bool("BT_FEED_DETAIL_LOG", True) def reset_bt_feed_sample_counter(*, postprocess: bool = False) -> None: """후처리 시작 시 샘플 카운터 리셋 — 코어 TPE에서 소진돼도 호가방 로그가 나오게.""" global _sample_logged, _pp_sample_logged if postprocess: _pp_sample_logged = 0 else: _sample_logged = 0 def log_bt_postprocess_ob_db_scope( db: Any, *, table: str, cols: Optional[List[str]] = None, source_filter: Optional[tuple] = None, date_from: str = "", date_to: str = "", context: str = "호가후처리", ) -> None: """후처리 호가 추천 직전 — 테이블·기간·source 건수 (코어 TPE 호가OFF 와 무관).""" try: from kis_trader.engine.feed_fallback import live_ob_primary primary = live_ob_primary() except Exception: primary = "?" sf = tuple(source_filter or ()) logger.info( "🔎 [%s] table=%s | 1차설정=%s | source_filter=%s | 기간=%s~%s", context, table, primary, sf or "(all)", (date_from or "?")[:10], (date_to or "?")[:10], ) colset = set(cols or []) if not db or "source" not in colset: if db and "source" not in colset: logger.info("🔎 [%s] source 컬럼 없음 — 벤더 비율 집계 스킵", context) return try: where: List[str] = [] params: List[Any] = [] df = str(date_from or "").replace("-", "").strip()[:8] dt = str(date_to or "").replace("-", "").strip()[:8] if len(df) == 8: where.append("snap_time >= %s") params.append(df + "000000") if len(dt) == 8: where.append("snap_time <= %s") params.append(dt + "235959") if sf: ph = ",".join(["%s"] * len(sf)) where.append(f"source IN ({ph})") params.extend(sf) wh = (" WHERE " + " AND ".join(where)) if where else "" sql = f"SELECT source, COUNT(*) AS n FROM {table}{wh} GROUP BY source ORDER BY n DESC" rows = db.conn.execute(sql, tuple(params)).fetchall() ctr: Counter = Counter() for r in rows or []: k = str((r.get("source") if isinstance(r, dict) else r[0]) or "?").strip().lower() or "?" n = int((r.get("n") if isinstance(r, dict) else r[1]) or 0) ctr[k] += n logger.info( "🔎 [%s DB벤더] %s", context, _fmt_counter(ctr) if ctr else "(0건 — 기간/필터 미스)", ) except Exception as e: logger.warning("⚠️ [%s] DB 벤더 집계 실패: %s", context, e) def maybe_log_bt_ob_postprocess_sample( *, code: str, buy_time: str, buy_price: float, snap_t: str = "", best_bid: int = 0, best_ask: int = 0, spread_pct: float = 0.0, bid_ask_ratio: float = 0.0, snap_source: str = "", hit: bool = True, context: str = "호가후처리샘플", ) -> None: """후처리: 체결↔호가 스냅 매칭 샘플 (상한 BT_FEED_DETAIL_LOG_MAX).""" global _pp_sample_logged if not bt_feed_detail_enabled(): return max_n = max(0, get_env_int("BT_FEED_DETAIL_LOG_MAX", 40)) if max_n <= 0 or _pp_sample_logged >= max_n: return try: from kis_trader.engine.feed_fallback import live_ob_primary op = live_ob_primary() alt = "kiwoom" if op == "kis" else "kis" src = str(snap_source or "").strip().lower() or ("없음" if not hit else "?") if hit: logger.info( "🔎 [%s] %s buy=%s px=%s | 호가1차설정=%s(체인 %s→%s→ls) | " "호가실제 src=%s snap=%s bid=%s ask=%s spr=%.3f%% or=%.3f", context, code, buy_time, int(buy_price or 0), op, op, alt, src, snap_t or "-", int(best_bid or 0), int(best_ask or 0), float(spread_pct or 0), float(bid_ask_ratio or 0), ) else: logger.info( "🔎 [%s] %s buy=%s px=%s | 호가1차설정=%s | 호가실제=없음(스냅 미스)", context, code, buy_time, int(buy_price or 0), op, ) _pp_sample_logged += 1 except Exception as e: logger.debug("호가후처리샘플 스킵: %s", e) def log_bt_feed_chain_banner(*, context: str = "Optuna/백테") -> None: """로드 직전 — 설정상 1·2·3차 체인만 (실매 format_trigger_feed_trace 머리와 동일).""" try: from kis_trader.engine.feed_fallback import live_ob_primary, live_tick_primary tp = live_tick_primary() op = live_ob_primary() alt_t = "kiwoom" if tp == "kis" else "kis" alt_o = "kiwoom" if op == "kis" else "kis" tick_src_env = "" try: import os tick_src_env = str(os.environ.get("TICK_SOURCE") or "").strip().lower() except Exception: pass extra = f" | TICK_SOURCE강제={tick_src_env}" if tick_src_env else "" logger.info( "🔎 [%s 피드체인] 틱1차=%s(체인 %s→%s→ls) | 호가1차=%s(체인 %s→%s→ls)%s", context, tp, tp, alt_t, op, op, alt_o, extra, ) except Exception as e: logger.debug("피드체인 배너 스킵: %s", e) def _pct(n: int, total: int) -> float: return (100.0 * n / total) if total > 0 else 0.0 def _fmt_counter(ctr: Counter, *, total: Optional[int] = None) -> str: tot = int(total if total is not None else sum(ctr.values())) if tot <= 0: return "(0건)" parts = [ f"{k or '?'}={v:,}({_pct(v, tot):.1f}%)" for k, v in ctr.most_common() ] return f"total={tot:,} | " + " ".join(parts) def count_tick_sources( ticks_by_code: Optional[Dict[str, Any]], ) -> Counter: """ticks_by_code {code: {minute: [tick|TickColumnView]}} → source Counter.""" ctr: Counter = Counter() if not ticks_by_code: return ctr try: from kis_trader.backtest.shared_ticks import TickColumnView except Exception: TickColumnView = () # type: ignore for _code, minutes in ticks_by_code.items(): if not isinstance(minutes, dict): continue for _mk, ticks in minutes.items(): if TickColumnView and isinstance(ticks, TickColumnView): owner = ticks.owner src_arr = getattr(owner, "_source", None) if src_arr is None: ctr["?"] += len(list(ticks.iter_idx())) continue for i in ticks.iter_idx(): try: s = src_arr[i].decode("utf-8").strip().lower() or "?" except Exception: s = "?" ctr[s] += 1 continue for t in (ticks or []): if not isinstance(t, dict): ctr["?"] += 1 continue s = str(t.get("source") or "").strip().lower() or "?" ctr[s] += 1 return ctr def count_orderbook_sources( orderbook_by_code: Optional[Dict[str, Any]], ) -> Counter: """orderbook_by_code {code: {minute: [OrderbookSnapshot|dict]}}.""" ctr: Counter = Counter() if not orderbook_by_code: return ctr for _code, minutes in orderbook_by_code.items(): if not isinstance(minutes, dict): continue for _mk, snaps in minutes.items(): for snap in (snaps or []): try: s = str(getattr(snap, "source", None) or "").strip().lower() if not s and isinstance(snap, dict): s = str(snap.get("source") or "").strip().lower() ctr[s or "?"] += 1 except Exception: ctr["?"] += 1 return ctr def log_bt_tick_feed_trace( ticks_by_code: Optional[Dict[str, Any]], *, table: str = "ws_ticks", main_src: str = "", raw_total: Optional[int] = None, context: str = "틱로드", ) -> Counter: """틱 로드·시간축 폴백 직후 — 벤더 비율 INFO.""" ctr = count_tick_sources(ticks_by_code) kept = sum(ctr.values()) try: from kis_trader.engine.feed_fallback import live_tick_primary primary = str(main_src or live_tick_primary()).strip().lower() or "?" except Exception: primary = str(main_src or "?").strip().lower() or "?" raw_bit = "" if raw_total is not None and int(raw_total) != kept: raw_bit = f" | raw={int(raw_total):,}→kept={kept:,}" logger.info( "🔎 [%s] table=%s | 1차설정=%s | 벤더 %s%s", context, table, primary, _fmt_counter(ctr, total=kept), raw_bit, ) return ctr def log_bt_orderbook_feed_trace( orderbook_by_code: Optional[Dict[str, Any]], meta: Optional[Dict[str, Any]] = None, *, context: str = "호가로드", ) -> Counter: """호가 스냅 로드 직후 — source(kiwoom_0d|ls_uh1|log_backfill|…) 비율.""" ctr = count_orderbook_sources(orderbook_by_code) meta = meta or {} hist = str(meta.get("orderbook_history_source") or "").strip().lower() or "?" rows = int(meta.get("ws_orderbook_rows_loaded") or sum(ctr.values()) or 0) try: from kis_trader.engine.feed_fallback import live_ob_primary primary = live_ob_primary() except Exception: primary = "?" logger.info( "🔎 [%s] history_source=%s | 1차설정=%s | rows=%s | 벤더 %s", context, hist, primary, f"{rows:,}", _fmt_counter(ctr), ) return ctr def maybe_log_bt_trigger_sample( code: str, eval_params: Optional[Dict[str, Any]], *, entry_price: float = 0.0, entry_time: str = "", entry_src: str = "", reject: str = "", context: str = "TRIGGER샘플", ) -> None: """매수 평가 직후 샘플 몇 건 — 실매 format_trigger_feed_trace 꼬리와 동일 축.""" global _sample_logged if not bt_feed_detail_enabled(): return max_n = max(0, get_env_int("BT_FEED_DETAIL_LOG_MAX", 40)) if max_n <= 0 or _sample_logged >= max_n: return p = eval_params or {} try: from kis_trader.engine.feed_fallback import ( extract_ob_trace_fields, format_trigger_feed_trace, tick_feed_tier, ) tick_rec: Dict[str, Any] = {} if entry_price and entry_src: vendor = "" es = str(entry_src or "") if ":" in es: vendor = es.split(":", 1)[1].strip().lower() tick_rec = { "vendor": vendor or "ws_ticks", "tier": 1, "label": es or "ws_ticks", "price": float(entry_price), "tick_time": str(entry_time or "")[:14], } ob_snap = p.get("_backtest_orderbook_snapshot") ob_rec: Dict[str, Any] = {} if ob_snap is not None: ob_rec = extract_ob_trace_fields(ob_snap) raw_src = str( ob_rec.get("ob_source") or getattr(ob_snap, "source", "") or "" ).strip().lower() # kiwoom_0d / ls_uh1 / kis → 체인 벤더 라벨 vendor = "ls" if raw_src.startswith("ls") else ( "kiwoom" if "kiwoom" in raw_src or raw_src == "log_backfill" else ( "kis" if "kis" in raw_src else (raw_src or "ob") ) ) ob_rec["vendor"] = vendor ob_rec["tier"] = tick_feed_tier(vendor, "") ob_rec["label"] = raw_src or vendor tail = format_trigger_feed_trace(tick_rec, ob_rec) rej = f" reject={reject}" if reject else "" logger.info( "🔎 [%s] %s entry_src=%s%s | %s", context, code, entry_src or "-", rej, tail, ) _sample_logged += 1 except Exception as e: logger.debug("TRIGGER샘플 스킵: %s", e) def tick_source_label(tick: Optional[Dict[str, Any]], fallback: str = "ws_ticks") -> str: """진입 source 문자열 — ws_ticks:kis / ws_ticks:kiwoom / ohlc_open.""" if not tick: return fallback src = str(tick.get("source") or "").strip().lower() if src: return f"ws_ticks:{src}" return "ws_ticks"