Files
willtools-demo/WillTools.extension/tests/test_runlog.py
T
will 8e6ee31596
ci / test (push) Successful in 6m18s
WillTools 2026-09-09 -- clean snapshot of the development repo for review
History-free snapshot of the private development repository at cbe45c5
(2026-09-09). Code, docs and public catalogue only; no plant or job
knowledge layers, no client or job names (tools/scrub.py clean). The
intro deck is left out of this snapshot because its slide images could
not be checked for job drawings.
2026-09-09 08:32:15 -05:00

301 lines
12 KiB
Python

# -*- coding: utf-8 -*-
"""Host tests for `vibe.runlog`, the run log (one JSON line per button run).
The module is deliberately engine-neutral -- IronPython 2.7 inside Revit and
host CPython 3 -- and imports nothing from the Revit side, so it is one of the
modules conftest.py can reach by path (it needs no `from vibe import ...`
import to be registered): `sys.modules['vibe']` is stubbed by the conftest
whose `__path__` points at the real `lib/vibe`, and plain imports of `runlog`
submodules resolve through it.
Every test points the log at a real temporary folder with
`monkeypatch.setenv('WILLTOOLS_RUNLOG_DIR', ...)` -- `log_dir()` re-resolves
the environment on every call, so no folder or state leaks between tests in
the same process. The questions asked are all "what exactly landed in the
file, in what order": whether record() writes one valid JSON line with the
fields the contract names, whether report_text is truncated at 20000 with the
marker, whether `run(...)` records 'ok' (or 'error' with a traceback, and
re-raises), whether a write failure is swallowed, and whether `tail(2)`
returns the last two records in written order.
"""
import io
import json
import os
import pytest
from vibe import runlog as R
# Module-level alias kept short for the test bodies below.
rl = R
def _set_dir(tmp_path, monkeypatch):
"""Point the run log at tmp_path and return its folder path as a string."""
folder = str(tmp_path)
monkeypatch.setenv(R.LOG_DIR_ENV, folder)
return folder
def _read_log(folder):
"""Every record in the log file as a list of dicts (raises on bad JSON)."""
path = os.path.join(folder, R._FILE_NAME)
assert os.path.isfile(path), 'expected a run log at {0}'.format(path)
with io.open(path, 'r', encoding='utf-8') as handle:
return [json.loads(line) for line in handle if line.strip()]
def _runlog_path(folder):
return os.path.join(folder, R._FILE_NAME)
# ------------------------------------------------------- the log_dir contract
def test_log_dir_prefers_the_env_var(tmp_path, monkeypatch):
folder = str(tmp_path)
monkeypatch.setenv(R.LOG_DIR_ENV, folder)
monkeypatch.delenv('APPDATA', raising=False)
assert R.log_dir() == folder
def test_log_dir_ignores_appdata_when_the_env_var_is_set(tmp_path, monkeypatch):
folder = str(tmp_path)
monkeypatch.setenv(R.LOG_DIR_ENV, folder)
monkeypatch.setenv('APPDATA', str(tmp_path / 'appdata'))
assert R.log_dir() == folder
# And APPDATA never gets created as a side effect of asking.
assert not (tmp_path / 'appdata').exists()
def test_log_dir_falls_back_to_appdata_when_env_unset(tmp_path, monkeypatch):
monkeypatch.delenv(R.LOG_DIR_ENV, raising=False)
appdata = str(tmp_path / 'appdata')
monkeypatch.setenv('APPDATA', appdata)
assert R.log_dir() == os.path.join(appdata, 'WillTools', 'runlog')
# Resolving the folder never creates it -- only record() mkdirs.
assert not os.path.exists(R.log_dir())
def test_log_dir_last_resort_is_home(tmp_path, monkeypatch):
monkeypatch.delenv(R.LOG_DIR_ENV, raising=False)
monkeypatch.delenv('APPDATA', raising=False)
expected = os.path.join(os.path.expanduser('~'), 'WillTools', 'runlog')
assert R.log_dir() == expected
assert not os.path.exists(R.log_dir())
# ------------------------------------------------------------- record basics
def test_record_writes_one_valid_json_line_with_the_fields(tmp_path,
monkeypatch):
folder = _set_dir(tmp_path, monkeypatch)
path = R.record('Panel Lift Check', doc_title='sample_job',
marks=['PNL101', 'PNL102'], outcome='ok',
report_text='everything fine',
report_path='C:/reports/x.html', error=None,
traceback_text=None, values={'count': 3, 'ok': True},
extra={'stage': 'pick'})
assert path is not None
assert path == _runlog_path(folder)
records = _read_log(folder)
assert len(records) == 1
entry = records[0]
assert entry['button'] == 'Panel Lift Check'
assert entry['doc_title'] == 'sample_job'
assert entry['marks'] == ['PNL101', 'PNL102']
assert entry['outcome'] == 'ok'
assert entry['report_text'] == 'everything fine'
assert entry['report_path'] == 'C:/reports/x.html'
assert entry['error'] is None
assert entry['traceback'] is None
assert entry['values'] == {'count': 3, 'ok': True}
assert entry['extra'] == {'stage': 'pick'}
assert 'T' in entry['ts'] and ':' in entry['ts']
def test_record_defaults_missing_fields_to_none(tmp_path, monkeypatch):
folder = _set_dir(tmp_path, monkeypatch)
path = R.record('A Button')
assert path is not None
entry = _read_log(folder)[0]
for key in ('doc_title', 'marks', 'outcome', 'report_text',
'report_path', 'error', 'traceback', 'values', 'extra'):
assert entry[key] is None, key
def test_record_creates_the_folder_on_demand(tmp_path, monkeypatch):
folder = str(tmp_path / 'a' / 'b')
monkeypatch.setenv(R.LOG_DIR_ENV, folder)
path = R.record('A Button')
assert path is not None
assert os.path.isdir(folder)
assert os.path.isfile(_runlog_path(folder))
def test_record_appends_rather_than_overwriting(tmp_path, monkeypatch):
folder = _set_dir(tmp_path, monkeypatch)
R.record('one')
R.record('two')
assert len(_read_log(folder)) == 2
# ------------------------------------------------------------- truncation
def test_report_text_is_truncated_at_20000_with_the_marker(tmp_path,
monkeypatch):
folder = _set_dir(tmp_path, monkeypatch)
body = 'x' * (R._REPORT_TEXT_CAP + 500)
R.record('Big Report', report_text=body)
entry = _read_log(folder)[0]
assert entry['report_text'].endswith(R._TRUNCATED_MARKER)
assert len(entry['report_text']) == R._REPORT_TEXT_CAP + len(
R._TRUNCATED_MARKER)
assert entry['report_text'].startswith('x' * R._REPORT_TEXT_CAP)
def test_report_text_at_the_cap_is_not_truncated(tmp_path, monkeypatch):
folder = _set_dir(tmp_path, monkeypatch)
body = 'y' * R._REPORT_TEXT_CAP
R.record('Exact Report', report_text=body)
entry = _read_log(folder)[0]
assert entry['report_text'] == body
assert not entry['report_text'].endswith(R._TRUNCATED_MARKER)
# ------------------------------------------------------------ run() success
def test_run_records_ok_with_the_bodys_fields(tmp_path, monkeypatch):
folder = _set_dir(tmp_path, monkeypatch)
seen = []
with rl.run('Panel Lift Check', 'sample_job', ['PNL1']) as ctx:
ctx.outcome = 'ok'
ctx.report_text = 'the body ran'
ctx.report_path = 'C:/reports/r.html'
ctx.values = {'pieces': 4}
ctx.extra = {'mode': 'dev'}
seen.append(ctx)
assert len(seen) == 1
ctx = seen[0]
assert ctx.path is not None
assert ctx.path == _runlog_path(folder)
entry = _read_log(folder)[0]
assert entry['button'] == 'Panel Lift Check'
assert entry['doc_title'] == 'sample_job'
assert entry['marks'] == ['PNL1']
assert entry['outcome'] == 'ok'
assert entry['report_text'] == 'the body ran'
assert entry['report_path'] == 'C:/reports/r.html'
assert entry['values'] == {'pieces': 4}
assert entry['extra'] == {'mode': 'dev'}
assert entry['error'] is None
assert entry['traceback'] is None
def test_run_defaults_outcome_to_ok_and_folds_lines_into_report_text(
tmp_path, monkeypatch):
folder = _set_dir(tmp_path, monkeypatch)
with rl.run('No Outcome Set') as ctx:
ctx.lines.append('first line')
ctx.lines.append('second line')
entry = _read_log(folder)[0]
assert entry['outcome'] == 'ok'
assert entry['report_text'] == 'first line\nsecond line'
def test_run_a_body_set_outcome_wins_over_lines_but_lines_do_not_override_text(
tmp_path, monkeypatch):
folder = _set_dir(tmp_path, monkeypatch)
with rl.run('Refused') as ctx:
ctx.outcome = 'refused'
ctx.report_text = 'user declined'
ctx.lines.append('ignored detail')
entry = _read_log(folder)[0]
assert entry['outcome'] == 'refused'
assert entry['report_text'] == 'user declined'
# ------------------------------------------------------------- run() error
def test_run_records_error_with_traceback_and_reraises(tmp_path, monkeypatch):
folder = _set_dir(tmp_path, monkeypatch)
with pytest.raises(ValueError) as caught:
with rl.run('Crashing Button', 'sample_job') as ctx:
ctx.report_text = 'up to the crash'
raise ValueError('boom')
assert 'boom' in str(caught.value)
entry = _read_log(folder)[0]
assert entry['button'] == 'Crashing Button'
assert entry['doc_title'] == 'sample_job'
assert entry['outcome'] == 'error'
assert entry['error'] == "ValueError('boom')"
assert 'Traceback (most recent call last)' in entry['traceback']
assert 'ValueError: boom' in entry['traceback']
assert entry['report_text'] == 'up to the crash'
assert entry['values'] is None
def test_run_error_still_folds_lines_when_no_report_text_was_set(
tmp_path, monkeypatch):
folder = _set_dir(tmp_path, monkeypatch)
with pytest.raises(RuntimeError):
with rl.run('Crashing') as ctx:
ctx.lines.append('half a report')
raise RuntimeError('kaboom')
entry = _read_log(folder)[0]
assert entry['outcome'] == 'error'
assert entry['report_text'] == 'half a report'
assert entry['error'] == "RuntimeError('kaboom')"
# ------------------------------------------------------- write-failure path
def test_a_write_failure_does_not_raise(tmp_path, monkeypatch):
# Point the log dir at a FILE, so os.makedirs / io.open must fail.
blocker = tmp_path / 'iamafile'
blocker.write_text('x', encoding='utf-8')
monkeypatch.setenv(R.LOG_DIR_ENV, str(blocker))
assert R.record('Lucky Button', report_text='still fine') is None
def test_a_write_failure_does_not_raise_inside_run(tmp_path, monkeypatch):
blocker = tmp_path / 'iamafile'
blocker.write_text('x', encoding='utf-8')
monkeypatch.setenv(R.LOG_DIR_ENV, str(blocker))
with rl.run('Lucky Button') as ctx:
ctx.report_text = 'body still ran'
# No exception escaped the body; rl.path records that the write failed.
assert ctx.path is None
# --------------------------------------------------------------------- tail()
def test_tail_returns_the_last_two_in_order(tmp_path, monkeypatch):
folder = _set_dir(tmp_path, monkeypatch)
for button in ('first', 'second', 'third', 'fourth'):
R.record(button)
last_two = R.tail(2)
assert [e['button'] for e in last_two] == ['third', 'fourth']
def test_tail_reads_across_a_full_record_after_a_bad_line(tmp_path,
monkeypatch):
# A torn line (a crash mid-write, say) must not hide the real records.
folder = _set_dir(tmp_path, monkeypatch)
path = _runlog_path(folder)
R.record('alpha')
with io.open(path, 'a', encoding='utf-8') as handle:
handle.write('{"button": "torn", "outc\n')
R.record('omega')
found = R.tail(10)
assert [e['button'] for e in found] == ['alpha', 'omega']
def test_tail_default_path_is_the_record_path(tmp_path, monkeypatch):
folder = _set_dir(tmp_path, monkeypatch)
R.record('only')
assert [e['button'] for e in R.tail()] == ['only']
def test_tail_of_a_missing_log_is_empty(tmp_path):
assert R.tail(5, path=str(tmp_path / 'nope.jsonl')) == []