feat(browser): 지역별 수집의 단계별 진행·경과 시간 INFO 로그

CHANGELOG.md

@@ -28,6 +28,10 @@ OpinetClient를 native async 하나로 통합했다. 모든 조회·디버그에
 - README 라이선스 표기 오류(MIT → GPL-3.0-or-later)를 실제 `pyproject.toml`/`LICENSE` 값과 일치하도록 정정.
 
 ### Added
+- 지역별 화면 수집(`OpinetBrowserCollector.collect_page`)이 단계별 진행을 `INFO` 로그로 남긴다:
+  지역 탐색의 시도별 진행·완료(지역 수), 탭(주유소/충전소) 시작·끝, 탭 안의 시도 단위 진행
+  (`done=i/N`, 누적 주유소 수, 재시도 수)과 탭·전체 경과 시간. 느린 호스트에서 어디서 시간이 드는지
+  보기 위한 것이며 지역 식별자는 기존 진단과 같은 정제 규칙(`_region_label`)을 따른다.
 - `opinet.experimental.OpinetBrowserCollector`: Playwright 기반 지역별 공개 화면 수집기. 시도·시군구·읍면동 목록, 주유소·충전소, 유종별 가격·갱신시각, 상표·부가정보·관찰 가능한 원시 응답 필드를 보존하며 요청 부하 분산용 무작위 화면 간격과 기본 8시간 수집 간격, 최근 24시간 최대 3회 실행 제한을 제공한다. 지역 AJAX/응답 상태 검증, 요청 상한, 접근 거부 감지, 리소스 정리와 실패 콜백을 포함한다.
 - 서비스키 공백/개행 자동 제거와 `.env` 기본 로드, 공식 5개 API 카탈로그(`get_api_catalog_options()` 등), Streamlit Debug Trace 표시용 `DebugRun`, fixture 저장/replay 문서와 예제 앱(`examples/streamlit_debug_app.py`).
 - `StationDetail.to_normalized()`와 `NormalizedFuelStationDetail`, `NormalizedFuelStationDetailPrice` DTO.

src/opinet/experimental/browser.py

@@ -923,9 +923,21 @@ async def _open_search_page(self, page: Any) -> None:
             raise OpinetServerError(f"Opinet browser navigation redirected to {final_url!r}")
 
     async def collect_page(self, page: Any) -> OpinetBrowserSnapshot:
-        """이미 열린 Playwright 페이지에서 한 번 전체 지역 수집을 실행한다."""
+        """이미 열린 Playwright 페이지에서 한 번 전체 지역 수집을 실행한다.
+
+        단계별 진행(지역 탐색 완료, 탭 시작·끝, 탭 안의 시도 단위 진행)과 경과 시간을 ``INFO`` 로그로
+        남긴다. 전체 수집이 수십 분~수 시간 걸리므로 호출자가 어디서 시간이 드는지 볼 수 있게 한다.
+        """
+        started = time.monotonic()
+        _logger.info("Opinet browser collection started: query_level=%s", self.query_level)
         regions = await self._discover_regions(page)
         query_regions = self._query_regions(regions)
+        _logger.info(
+            "Opinet browser region discovery finished: regions=%d query_regions=%d elapsed=%.0fs",
+            len(regions),
+            len(query_regions),
+            time.monotonic() - started,
+        )
         if not query_regions:
             raise OpinetServerError("Opinet browser returned no queryable regions")
         search_request_count = len(query_regions) * 2
@@ -939,9 +951,17 @@ async def collect_page(self, page: Any) -> OpinetBrowserSnapshot:
         retry_budget = self.throttle.max_search_requests - search_request_count
 
         retried = 0
+        total = len(query_regions)
         for station_kind, tab_selector in _TAB_SELECTORS.items():
+            tab_started = time.monotonic()
+            _logger.info(
+                "Opinet browser tab started: kind=%s query_regions=%d elapsed=%.0fs",
+                station_kind,
+                total,
+                tab_started - started,
+            )
             await self._activate_tab(page, station_kind=station_kind, selector=tab_selector)
-            for region in query_regions:
+            for index, region in enumerate(query_regions, start=1):
                 found, region_retried = await self._search_region_with_retry(
                     page,
                     region,
@@ -955,7 +975,35 @@ async def collect_page(self, page: Any) -> OpinetBrowserSnapshot:
                     key = _station_key(station)
                     previous = stations.get(key)
                     stations[key] = station if previous is None else _merge_station(previous, station)
+                if index == total or query_regions[index].sido_value != region.sido_value:
+                    _logger.info(
+                        "Opinet browser tab progress: kind=%s sido=%s done=%d/%d stations=%d retries=%d "
+                        "tab_elapsed=%.0fs elapsed=%.0fs",
+                        station_kind,
+                        _region_label(region.sido_value),
+                        index,
+                        total,
+                        len(stations),
+                        retried,
+                        time.monotonic() - tab_started,
+                        time.monotonic() - started,
+                    )
+            _logger.info(
+                "Opinet browser tab finished: kind=%s query_regions=%d stations=%d tab_elapsed=%.0fs elapsed=%.0fs",
+                station_kind,
+                total,
+                len(stations),
+                time.monotonic() - tab_started,
+                time.monotonic() - started,
+            )
 
+        _logger.info(
+            "Opinet browser collection finished: regions=%d stations=%d retries=%d elapsed=%.0fs",
+            len(regions),
+            len(stations),
+            retried,
+            time.monotonic() - started,
+        )
         return OpinetBrowserSnapshot(
             collected_at=datetime.now(_SEOUL),
             source_url=self.url,
@@ -1118,11 +1166,12 @@ async def _select_value(self, page: Any, selector: str, value: str, *, parent: s
 
     async def _discover_regions(self, page: Any) -> list[BrowserRegion]:
         regions: list[BrowserRegion] = []
+        started = time.monotonic()
         await self._wait_for_options(page, "#SIDO_NM0")
         sidos = await self._read_options(page, "#SIDO_NM0")
         if not sidos:
             raise OpinetServerError("Opinet browser returned no sido options")
-        for sido_value, sido_name in sidos:
+        for sido_index, (sido_value, sido_name) in enumerate(sidos, start=1):
             await self._select_value(page, "#SIDO_NM0", sido_value)
             sigungus = await self._read_options(page, "#SIGUNGU_NM0")
             if not sigungus:
@@ -1151,6 +1200,15 @@ async def _discover_regions(self, page: Any) -> list[BrowserRegion]:
                             sigungu_name=sigungu_name,
                         )
                     )
+            _logger.info(
+                "Opinet browser region discovery progress: sido=%s done=%d/%d sigungu=%d regions=%d elapsed=%.0fs",
+                _region_label(sido_value),
+                sido_index,
+                len(sidos),
+                len(sigungus),
+                len(regions),
+                time.monotonic() - started,
+            )
         return regions
 
     def _query_regions(self, regions: Sequence[BrowserRegion]) -> tuple[BrowserRegion, ...]:

tests/test_experimental_browser.py

@@ -1408,3 +1408,48 @@ async def discover(_page):
     assert [kind for _, kind, _ in calls] == ["station", "station", "lpg", "lpg"]
     assert len(snapshot.stations) == 1
     assert snapshot.region_retry_count == 2
+
+
+@pytest.mark.asyncio
+async def test_browser_collect_page_logs_stage_progress_per_sido(monkeypatch, region, caplog):
+    seoul_a = replace(region, sido_value="11", sido_name="서울", dong_value=None, dong_name=None)
+    seoul_b = replace(seoul_a, sigungu_value="11680", sigungu_name="강남구")
+    busan = replace(seoul_a, sido_value="26", sido_name="부산", sigungu_value="26110", sigungu_name="중구")
+    collector = OpinetBrowserCollector(throttle=OpinetBrowserThrottle(action_min_seconds=0, action_max_seconds=0))
+
+    async def discover(_page):
+        return [seoul_a, seoul_b, busan]
+
+    async def search(_page, _query_region, *, station_kind):
+        return ()
+
+    monkeypatch.setattr(collector, "_discover_regions", discover)
+    monkeypatch.setattr(collector, "_search_region", search)
+    with caplog.at_level("INFO", logger="opinet.experimental.browser"):
+        await collector.collect_page(_FakeTabPage())
+    messages = [record.getMessage() for record in caplog.records]
+    assert any(m.startswith("Opinet browser region discovery finished: regions=3 query_regions=3") for m in messages)
+    progress = [m for m in messages if m.startswith("Opinet browser tab progress:")]
+    # 탭마다 시도가 바뀔 때와 마지막에 한 줄씩: 서울(2/3), 부산(3/3).
+    assert [m.split(" stations=")[0] for m in progress] == [
+        "Opinet browser tab progress: kind=station sido=11 done=2/3",
+        "Opinet browser tab progress: kind=station sido=26 done=3/3",
+        "Opinet browser tab progress: kind=lpg sido=11 done=2/3",
+        "Opinet browser tab progress: kind=lpg sido=26 done=3/3",
+    ]
+    assert all("elapsed=" in m for m in progress)
+    assert sum(m.startswith("Opinet browser tab started:") for m in messages) == 2
+    assert sum(m.startswith("Opinet browser tab finished:") for m in messages) == 2
+    assert messages[-1].startswith("Opinet browser collection finished: regions=3 stations=0 retries=0 elapsed=")
+
+
+@pytest.mark.asyncio
+async def test_browser_region_discovery_logs_each_sido(caplog):
+    collector = OpinetBrowserCollector(
+        throttle=OpinetBrowserThrottle(action_min_seconds=0.0, action_max_seconds=0.0), query_level="dong",
+    )
+    with caplog.at_level("INFO", logger="opinet.experimental.browser"):
+        await collector._discover_regions(_FakeRegionPage())
+    lines = [r.getMessage() for r in caplog.records if r.getMessage().startswith("Opinet browser region discovery progress:")]
+    assert len(lines) == 1
+    assert lines[0].startswith("Opinet browser region discovery progress: sido=11 done=1/1 sigungu=1 regions=")