ecw-charge-validation/tests/test_run_events.py

"""
Run events — `core/run_events.py` (spec 2026-10-22 Stage 1, EEWA-31).

    python tests\\test_run_events.py

Every Run writes its events, each with its time, to
`Logs\\events_<run>.jsonl` beside `run_<run>.log`. What has to hold:

  * **The file sits beside the log, named after it**, so the Portal finds a
    Run's events from the log path `bot_run.json` already holds.
  * **One JSON object per line, flushed at once** — a killed Run still
    leaves every event it wrote.
  * **An event never stops a Run**: no file, a bad value, a closed handle —
    the event is dropped and the Run goes on.
  * **eCW Login Attempts are numbered** and every step carries its attempt.
  * **A Run Error carries the traceback** of the exception that caused it.
  * **No secret reaches the file**: the run_start fields are a fixed list.
"""

import os
import sys
import json
import pathlib
import tempfile

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

from ecw_bot.core import run_events          # noqa: E402

CASES = []


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


def _fresh():
    run_events._reset()
    d = pathlib.Path(tempfile.mkdtemp())
    log = d / "run_20261022_141530.log"
    log.write_text("")
    return log


def _read(log):
    path = run_events.path_for(log)
    return [json.loads(l) for l in path.read_text(encoding="utf-8").splitlines()]


@case
def the_events_file_is_named_after_the_log():
    log = pathlib.Path(r"D:\x\Logs\run_20261022_141530.log")
    assert run_events.path_for(log).name == "events_20261022_141530.jsonl"
    assert run_events.path_for(log).parent == log.parent
    assert run_events.run_id_of(log) == "20261022_141530"


@case
def start_writes_run_start_with_source_and_who():
    log = _fresh()
    os.environ["ECW_STARTED_BY"] = "asha"
    os.environ["ECW_RUN_SOURCE"] = "web"
    try:
        run_events.start(log, mode="VERIFY", claim_limit=20,
                         test_sheet=r"D:\Ecw Process\Input\sheet.xlsx")
    finally:
        del os.environ["ECW_STARTED_BY"], os.environ["ECW_RUN_SOURCE"]
    ev = _read(log)
    assert len(ev) == 1 and ev[0]["kind"] == "run_start", ev
    e = ev[0]
    assert e["started_by"] == "asha" and e["source"] == "portal", e
    assert e["mode"] == "VERIFY" and e["claim_limit"] == 20, e
    assert e["test_sheet"] == "sheet.xlsx", e        # file name only
    assert e["pid"] == os.getpid() and "t" in e, e
    assert len(e["t"]) == 23, e["t"]                  # ms: 2026-10-22T14:15:30.123


@case
def a_terminal_run_is_started_by_the_windows_user():
    log = _fresh()
    os.environ.pop("ECW_STARTED_BY", None)
    os.environ.pop("ECW_RUN_SOURCE", None)
    run_events.start(log, mode="VERIFY")
    e = _read(log)[0]
    assert e["source"] == "terminal", e
    assert e["started_by"] and e["started_by"] == run_events._windows_user(), e


@case
def emit_appends_one_line_per_event():
    log = _fresh()
    run_events.start(log, mode="VERIFY")
    run_events.emit("queue", claims=["1", "2"])
    run_events.warning("not_found", "not in eCW", claim="2")
    ev = _read(log)
    assert [e["kind"] for e in ev] == ["run_start", "queue", "warning"], ev
    assert ev[2]["code"] == "not_found" and ev[2]["claim"] == "2", ev[2]


@case
def login_attempts_are_numbered_and_steps_carry_the_attempt():
    log = _fresh()
    run_events.start(log, mode="VERIFY")
    run_events.login_attempt_start()
    run_events.login_step("page_open")
    run_events.login_attempt_end("twofa_timeout", "no mail")
    run_events.login_attempt_start()
    run_events.login_step("home")
    run_events.login_attempt_end("ok")
    ev = [e for e in _read(log) if e["kind"] != "run_start"]
    assert [(e["kind"], e["attempt"]) for e in ev] == [
        ("login_attempt_start", 1), ("login_step", 1),
        ("login_attempt_end", 1), ("login_attempt_start", 2),
        ("login_step", 2), ("login_attempt_end", 2)], ev
    assert ev[2]["result"] == "twofa_timeout" and ev[2]["message"] == "no mail"
    assert ev[1]["step"] == "page_open"


@case
def a_run_error_carries_the_traceback():
    log = _fresh()
    run_events.start(log, mode="VERIFY")
    try:
        raise ValueError("boom")
    except ValueError as exc:
        run_events.run_error("claims", str(exc), 5, exc=exc)
    e = _read(log)[-1]
    assert e["kind"] == "run_error" and e["exit_code"] == 5, e
    assert e["step"] == "claims" and e["message"] == "boom", e
    assert "ValueError: boom" in e["traceback"], e["traceback"]


@case
def a_run_error_without_an_exception_has_no_traceback():
    log = _fresh()
    run_events.start(log, mode="VERIFY")
    run_events.run_error("config", "ECW_URL is not set", 2)
    assert _read(log)[-1]["traceback"] == ""


@case
def before_start_and_after_a_failure_nothing_raises():
    run_events._reset()
    run_events.emit("queue", claims=[])             # not started: dropped
    run_events.warning("x", "y")
    log = _fresh()
    run_events.start(log, mode="VERIFY")
    run_events.emit("odd", value=object())          # not JSON: str() it
    assert _read(log)[-1]["value"].startswith("<object"), _read(log)[-1]
    run_events._handle.close()                      # handle gone: dropped
    run_events.emit("queue", claims=[])


@case
def start_into_a_missing_folder_does_not_raise():
    run_events._reset()
    run_events.start(pathlib.Path(r"Z:\no\such\run_20261022_000000.log"),
                     mode="VERIFY")
    run_events.emit("queue", claims=[])


@case
def append_to_writes_into_an_ended_runs_file():
    log = _fresh()
    run_events.start(log, mode="VERIFY")
    run_events._reset()
    run_events.append_to(log, "stopped", stopped_by="asha")
    ev = _read(log)
    assert ev[-1]["kind"] == "stopped" and ev[-1]["stopped_by"] == "asha", ev


def main() -> int:
    failures = 0
    for fn in CASES:
        name = fn.__name__.replace("_", " ")
        try:
            fn()
            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
    run_events._reset()
    print(f"\n{len(CASES) - failures}/{len(CASES)} passed")
    return 1 if failures else 0


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