ecw-charge-validation/tests/test_progress_note_wait.py

r"""
Progress Notes: polled, not slept on (review item D8).

    python tests\test_progress_note_wait.py

The old `open_progress_notes` clicked, slept a fixed 3 s and probed once. The
logs show 3 misses in ~115 note reads, and in every one the viewer had opened
on a document that had not loaded yet — so the claim was reported Clean with
telehealth never checked. Now the note is polled every 250 ms for up to
`PROGRESS_NOTE_WAIT_MS`, accepted once its `[prisma-section]` count holds
still, with one retry of the click if nothing opened at all.

Local headless chromium against `tests\fixtures\progress_note_delayed.html`
(the note arrives late, never, only on a second click, or never settles).
`PROGRESS_NOTE_WAIT_MS` is shrunk per case so the suite stays quick. No eCW;
screenshots go to a temp folder.
"""

import io
import sys
import time
import types
import pathlib
import inspect
import tempfile
import contextlib

ROOT = pathlib.Path(__file__).resolve().parent.parent
sys.path.insert(0, str(ROOT / "src"))

HOST = pathlib.Path(__file__).resolve().parent / "fixtures" / \
    "progress_note_delayed.html"

from ecw_bot import settings as cfg                 # noqa: E402
from ecw_bot.pages import claim_form, progress_note  # noqa: E402
from ecw_bot.selectors import claim_form as sel     # noqa: E402

CASES = []


def case(fn):
    CASES.append(fn)
    return fn


def _open(page, query: str, wait_ms: int):
    """open_progress_notes against the fixture: (note, seconds, log)."""
    page.goto(HOST.as_uri() + "?" + query)
    orig = cfg.PROGRESS_NOTE_WAIT_MS
    cfg.PROGRESS_NOTE_WAIT_MS = wait_ms
    buf = io.StringIO()
    started = time.monotonic()
    try:
        with contextlib.redirect_stdout(buf):
            note = claim_form.open_progress_notes(page)
    finally:
        cfg.PROGRESS_NOTE_WAIT_MS = orig
    return note, time.monotonic() - started, buf.getvalue()


@case
def a_note_that_loads_after_the_old_3s_sleep_is_read(page):
    """3.5 s: the old sleep-3-then-probe-once returned "nothing" here."""
    note, took, log = _open(page, "mode=slow&delay=3500", 10_000)
    assert note.get("opened") == "frame", (note, log)
    codes = [p["code"] for p in note.get("procedure_codes") or []]
    assert "H0023" in codes, codes
    assert took >= 3.5, f"read after {took:.1f}s — before the note existed"
    assert "Note loaded in the frame" in log, log
    assert "partial" not in note, "a note that settled was marked partial"


@case
def a_note_that_loads_quickly_is_accepted_in_about_a_second(page):
    """The normal claim no longer pays a fixed 3 s."""
    note, took, _ = _open(page, "mode=slow&delay=200", 10_000)
    assert note.get("opened") == "frame", note
    assert took < 2.5, f"took {took:.1f}s on a note that loaded in 0.2s"


@case
def a_note_that_never_appears_is_nothing_within_the_configured_wait(page):
    note, took, log = _open(page, "mode=never", 2_000)
    assert note == {"opened": "nothing"}, note
    assert 1.8 <= took < 5.0, f"took {took:.1f}s for a 2s wait"
    # A viewer WAS open (slow-document case), so no second click was made.
    assert page.evaluate("window.progNoteClicks") == 1, log
    # And the viewer was closed on the way out.
    assert page.locator(sel.SEL_PN_CLOSE).count() == 0, "viewer left open"


@case
def a_click_that_did_not_take_is_retried_once(page):
    note, _, log = _open(page, "mode=reclick", 3_000)
    assert note.get("opened") == "frame", (note, log)
    assert page.evaluate("window.progNoteClicks") == 2
    assert "clicking Prog. Notes once more" in log, log


@case
def a_note_that_never_settles_is_read_anyway_and_logged_as_partial(page):
    note, took, log = _open(page, "mode=growing", 2_000)
    assert note.get("opened") == "frame", (note, log)
    assert note.get("sections"), note
    assert "may be partial" in log, log
    assert took < 5.0, f"took {took:.1f}s"
    # On the note, not only in the log, so the summary can act on it.
    assert note.get("partial") is True, note
    assert note.get("partial_sections", 0) >= 1, note


@case
def a_note_header_with_no_sections_is_read_but_marked_partial(page):
    """
    The note's header arrives and not one section under it: read at the
    deadline, it has no Procedure Codes, so telehealth is never seen — the
    D8 false Clean. The log line alone could not stop that; the mark on the
    note is what the summary can turn into a Review row.
    """
    note, _, log = _open(page, "mode=empty", 1_500)
    assert note.get("opened") == "frame", (note, log)
    assert note.get("partial") is True, note
    assert note.get("partial_sections") == 0, note
    assert not note.get("procedure_codes"), note


@case
def section_count_never_raises():
    class Broken:
        def evaluate(self, *a, **k):
            raise RuntimeError("frame detached")
    assert progress_note.section_count(Broken()) == 0


@case
def polling_find_does_not_repeat_the_60s_tab_load_wait():
    """
    find() waits on each new tab's domcontentloaded; at its 60s default, a
    poll every 250 ms could sit a minute per poll. The poll passes 1s.
    """
    waits = []
    tab = types.SimpleNamespace(
        wait_for_load_state=lambda state, timeout: waits.append(timeout),
        evaluate=lambda *a: False)
    fake = types.SimpleNamespace(
        context=types.SimpleNamespace(pages=["claim page", tab]),
        frames=[], main_frame=None)
    assert progress_note.find(fake, tabs_before=1, load_timeout=1_000) == \
        (None, "nothing")
    assert waits == [1_000], waits

    calls = []
    orig_find, orig_wait = progress_note.find, cfg.PROGRESS_NOTE_WAIT_MS
    progress_note.find = lambda page, **kw: (calls.append(kw)
                                             or (None, "nothing"))
    cfg.PROGRESS_NOTE_WAIT_MS = 0
    fake_page = types.SimpleNamespace(
        context=types.SimpleNamespace(pages=[]),
        wait_for_timeout=lambda ms: None)
    try:
        with contextlib.redirect_stdout(io.StringIO()):
            claim_form._wait_for_note(fake_page, 0)
    finally:
        progress_note.find, cfg.PROGRESS_NOTE_WAIT_MS = orig_find, orig_wait
    assert calls and all(kw.get("load_timeout") == 1_000 for kw in calls), \
        calls


@case
def a_note_whose_document_stalls_mid_stream_is_not_taken_early(page):
    """
    Final review, 2026-10-05: the note is a whole HTML document, so a slow
    server delivers it in pieces. Here two sections are parsed, then the
    stream stalls for 1.5 s with readyState still "loading" — the same
    count on every poll. A count-only check took the note at ~0.25 s,
    without its Procedure Codes, unmarked: the D8 false Clean again.
    """
    note, took, log = _open(page, "mode=stalled&delay=1500", 6_000)
    assert note.get("opened") == "frame", (note, log)
    codes = [p["code"] for p in note.get("procedure_codes") or []]
    assert codes == ["H0023"], (codes, log)
    assert "partial" not in note, note
    assert took >= 1.5, f"read after {took:.1f}s — mid-stream"


@case
def a_stall_that_never_ends_is_read_at_the_deadline_as_partial(page):
    """Still "loading" at the deadline: read anyway, and marked partial."""
    note, _, log = _open(page, "mode=stalled&delay=60000", 1_500)
    assert note.get("opened") == "frame", (note, log)
    assert note.get("partial") is True, note
    assert note.get("partial_sections") == 2, note


@case
def an_earlier_claims_note_left_in_a_reused_viewer_is_not_read(page):
    """
    Final review, 2026-10-05: Close may only hide the viewer, and a reused
    iframe still shows the previous claim's note until the new one commits.
    Without the pre-click mark, A1111 (the earlier claim) was read as this
    claim's note on the first two polls.
    """
    note, took, log = _open(page, "mode=reused&delay=1500", 6_000)
    assert note.get("opened") == "frame", (note, log)
    codes = [p["code"] for p in note.get("procedure_codes") or []]
    assert codes == ["H0023"], (codes, log)
    assert took >= 1.5, f"read after {took:.1f}s — before this claim's note"
    assert "earlier note document(s) still on the page" in log, log


@case
def a_note_in_a_slow_new_tab_gets_no_second_click_and_no_close_wait(page):
    """
    The tab opens at once but its note arrives past the halfway point.
    A new tab is the note on its way, so Prog. Notes is NOT clicked again
    (that would open a second tab). And with no in-page viewer, closing
    is an instant check, not a 5 s wait for a Close button that is not
    there (final review, 2026-10-05).
    """
    tabs = len(page.context.pages)
    note, took, log = _open(page, "mode=tab&delay=2000", 3_000)
    assert note.get("opened") == "tab", (note, log)
    codes = [p["code"] for p in note.get("procedure_codes") or []]
    assert "H0023" in codes, codes
    assert page.evaluate("window.progNoteClicks") == 1, log
    assert "clicking Prog. Notes once more" not in log, log
    assert took < 4.5, f"took {took:.1f}s — the 5s close wait is back"
    assert len(page.context.pages) == tabs, "the note's tab was left open"


def _settings_default(key: str):
    """
    `key`'s code default: settings.py run afresh with no .env beside it (the
    frozen-exe branch points ROOT at an empty temp folder — the same probe
    tests/test_settings.py uses) and the key unset in the environment.
    """
    import os
    import importlib.util
    saved = os.environ.pop(key, None)
    had_frozen = hasattr(sys, "frozen")
    saved_frozen, saved_exe = getattr(sys, "frozen", None), sys.executable
    with tempfile.TemporaryDirectory() as tmp:
        try:
            sys.frozen = True
            sys.executable = str(pathlib.Path(tmp) / "bot.exe")
            spec = importlib.util.spec_from_file_location(
                "ecw_bot._settings_probe", cfg.__file__)
            probe = importlib.util.module_from_spec(spec)
            with contextlib.redirect_stdout(io.StringIO()):
                spec.loader.exec_module(probe)
            assert probe.ROOT != cfg.ROOT, "the probe used the real .env"
            return getattr(probe, key)
        finally:
            sys.executable = saved_exe
            if had_frozen:
                sys.frozen = saved_frozen
            else:
                del sys.frozen
            if saved is not None:
                os.environ[key] = saved


@case
def the_wait_is_a_setting_with_a_20s_default():
    # The code default, from a probe with no .env — not settings.py's source
    # text (a reformat broke that) and not the operator's .env.
    assert _settings_default("PROGRESS_NOTE_WAIT_MS") == 20_000
    assert isinstance(cfg.PROGRESS_NOTE_WAIT_MS, int)


def main() -> int:
    if not HOST.exists():
        print(f"  FAIL  fixture missing: {HOST}")
        return 1
    try:
        from playwright.sync_api import sync_playwright
    except ImportError:
        print("  SKIP  playwright is not installed")
        return 0

    failures = 0
    orig_shots = cfg.SCREENSHOTS
    with tempfile.TemporaryDirectory() as tmp, sync_playwright() as pw:
        cfg.SCREENSHOTS = pathlib.Path(tmp)
        browser = pw.chromium.launch(headless=True)
        page = browser.new_page()
        try:
            for fn in CASES:
                name = fn.__name__.replace("_", " ")
                try:
                    if len(inspect.signature(fn).parameters) == 0:
                        fn()
                    else:
                        fn(page)
                    print(f"  ok    {name}")
                except AssertionError as exc:
                    print(f"  FAIL  {name}: {exc}")
                    failures += 1
                except Exception as exc:
                    print(f"  ERROR {name}: {type(exc).__name__}: {exc}")
                    failures += 1
        finally:
            cfg.SCREENSHOTS = orig_shots
            browser.close()

    print(f"\n{len(CASES) - failures}/{len(CASES)} passed")
    return 1 if failures else 0


if __name__ == "__main__":
    sys.exit(main())