diff --git a/NLPPlus/__init__.py b/NLPPlus/__init__.py index 6f9ad5e..bc86074 100644 --- a/NLPPlus/__init__.py +++ b/NLPPlus/__init__.py @@ -17,6 +17,7 @@ from typing import Optional, Any import os import glob +import time LOGGER = logging.getLogger("NLPPlus") @@ -107,6 +108,58 @@ def __init__(self, analyzer_name, timeout: float): f"{timeout:g}s and was stopped") +class AnalyzerError(EngineException, Exception): + """The analyzer could not be loaded, so nothing was analyzed. + + Raised when the analyzer folder is missing, its knowledge base does not + load, or its passes do not build (eg an NLP++ syntax error). Before + this, :meth:`Engine.analyze` returned normally with empty output. + + ``log`` holds what the engine wrote to the analyzer's + ``logs/make_ana.log`` and ``logs/cgerr.log`` during the failed call + (empty if it wrote neither); ``make_ana.log`` lines read + `` [message]``. The message repeats the lines that are + not routine. + + Also an :class:`Exception`, unlike :class:`EngineException`, so code + that handles ordinary errors handles this one too. + """ + + def __init__(self, analyzer_name, log: str = ""): + self.analyzer_name = str(analyzer_name) + self.log = log + msg = f"analyzer {self.analyzer_name} failed to load" + details = [l for l in log.splitlines() if _is_diagnostic(l)] + if details: + msg += ":\n " + "\n ".join(details) + super().__init__(msg) + + +_ROUTINE_LOG = ("[Date:", "[Build analyzer time", "[Starting up KB", + "[Loading interpreted kb", "[CG: Trying to load compiled KB") + + +def _is_diagnostic(line: str) -> bool: + msg = line[line.find("["):] if "[" in line else "" + return bool(msg) and not msg.startswith(_ROUTINE_LOG) + + +def _read_failure_logs(anadir: Path, since: float) -> str: + """The engine's logs for a failed load, if this call wrote them.""" + parts = [] + for name in ("make_ana.log", "cgerr.log"): + path = anadir / "logs" / name + try: + if path.stat().st_mtime < since: + continue # Left by an earlier run. + # The engine ends each message with std::ends, a NUL. + text = path.read_text(encoding="utf-8", errors="replace") + parts.append(text.replace("\x00", "")) + except OSError: + pass + return "".join(parts) + + class Results: """Various results produced by the NLP++ analyzer.""" @@ -315,15 +368,26 @@ def analyze(self, text: str, analyzer_name: PathLike, develop: bool = False, :class:`AnalysisStopped` is raised. Without one, an analyzer whose loop never ends cannot be stopped short of killing the process. + + Raises :class:`AnalyzerError`, with the engine's diagnostics, if + the analyzer could not be loaded (missing, bad KB, or a pass that + does not build). """ outdir = self.analyzer_dir(analyzer_name) / "output" # Delete the files of the previous run in the outdir. for file_path in glob.glob(str(outdir / "*")): if os.path.isfile(file_path): os.remove(file_path) - outtext = self.engine.analyze(self._engine_analyzer_arg(analyzer_name), - text, develop, compiled, datum or "", - timeout if timeout and timeout > 0 else 0.0) + started = time.time() - 1 # mtime granularity. + try: + outtext = self.engine.analyze( + self._engine_analyzer_arg(analyzer_name), text, develop, + compiled, datum or "", + timeout if timeout and timeout > 0 else 0.0) + except RuntimeError: + anadir = self.analyzer_dir(analyzer_name) + raise AnalyzerError(analyzer_name, + _read_failure_logs(anadir, started)) from None if timeout and timeout > 0 and self.engine.last_run_stopped(): raise AnalysisStopped(analyzer_name, timeout) return Results(outtext, outdir) @@ -355,8 +419,14 @@ def compile(self, analyzer_name: PathLike, develop: bool = False, # With an analyzers folder set, this used to return # /analyzers/, which does not exist, so cloud_compile # failed with "Analyzer directory not found". - self.engine.compile(self._engine_analyzer_arg(analyzer_name), develop, - kb_only, analyzer_only) + started = time.time() - 1 # mtime granularity. + try: + self.engine.compile(self._engine_analyzer_arg(analyzer_name), + develop, kb_only, analyzer_only) + except RuntimeError: + anadir = self.analyzer_dir(analyzer_name) + raise AnalyzerError(analyzer_name, + _read_failure_logs(anadir, started)) from None return self.analyzer_dir(analyzer_name) def cloud_compile(self, analyzer_name: str, diff --git a/bindings.cpp b/bindings.cpp index b24f3cc..27fc0c2 100644 --- a/bindings.cpp +++ b/bindings.cpp @@ -2,6 +2,7 @@ #include #include #include +#include #include #ifndef _WIN32 #include @@ -127,6 +128,12 @@ wrap_analyze(NLP_ENGINE &engine, const std::string &parser, /*compile*/false, compiled, /*compileKB*/false); free(_parser); + // A negative return means the analyzer never ran: it was not found, + // its KB did not load, or its passes did not build. The engine only + // says so on its own stderr, which Python cannot capture on Windows, + // so the caller used to get "" back as if the run had found nothing. + if (rv < 0) + throw std::runtime_error("analyzer failed to load: " + parser); return outstream.str(); } @@ -156,10 +163,14 @@ wrap_compile(NLP_ENGINE &engine, const std::string &analyzer, const bool develop, const bool kbOnly, const bool analyzerOnly) { CLocaleGuard cLocale; _TCHAR *_analyzer = _tcsdup(analyzer.c_str()); - engine.init(_analyzer, develop, /*silent*/false, - /*compile*/(!kbOnly && !analyzerOnly), /*compiled*/false, - /*compileKB*/kbOnly, /*compileAna*/analyzerOnly); + int rv = engine.init(_analyzer, develop, /*silent*/false, + /*compile*/(!kbOnly && !analyzerOnly), /*compiled*/false, + /*compileKB*/kbOnly, /*compileAna*/analyzerOnly); free(_analyzer); + // As in wrap_analyze: a failed build used to return normally having + // generated nothing. + if (rv < 0) + throw std::runtime_error("analyzer failed to load: " + analyzer); } /** diff --git a/tests/test_load_errors.py b/tests/test_load_errors.py new file mode 100644 index 0000000..4c37f7b --- /dev/null +++ b/tests/test_load_errors.py @@ -0,0 +1,117 @@ +"""A failed analyzer load must raise, not return empty output. + +The engine reports a missing analyzer, a KB that does not load, or a pass +that does not build only on its own stderr, which Python cannot capture +on Windows. analyze() and compile() used to return normally, so callers +had to guess a build failure from every output coming back empty. + +Also checks that logs/make_ana.log, which the error reads, is written, +and that a .kbb file with CRLF line ends (a Windows checkout) loads on +every platform (nlp-engine 4.2.52+). +""" + +import shutil +import unittest +from pathlib import Path +from tempfile import TemporaryDirectory + +import NLPPlus + +NLPPLUSDIR = Path(NLPPlus.__file__).parent + + +def engine_at_least(*want): + try: + have = tuple(int(n) for n in NLPPlus.bindings.engine_version().split(".")) + except ValueError: + return True # "unknown": a local build of the current engine. + return have >= want + + +SEQ = "tokenize\tnil\t# tok\nnlp\tmain\t# main\n" +GOOD = """@CODE +L("v") = findconcept(findroot(), "verbs"); +L("o") = "verbs=" + conceptname(L("v")); +if (L("v")) + L("o") = L("o") + " k=" + strval(down(L("v")), "k"); +"result.txt" << L("o"); +@@CODE +""" +BAD = '@CODE\nL("x") = ;\n@@CODE\n' + + +class LoadErrorTest(unittest.TestCase): + + def setUp(self): + self.tmp = TemporaryDirectory(prefix="test-nlpplus-", + ignore_cleanup_errors=True) + self.work = Path(self.tmp.name) + (self.work / "analyzers").mkdir() + shutil.copytree(NLPPLUSDIR / "data", self.work / "data") + self.engine = NLPPlus.Engine(self.work) + + def tearDown(self): + self.engine.close() + self.tmp.cleanup() + + def make(self, name, main, eol="\n"): + d = self.work / "analyzers" / name + (d / "spec").mkdir(parents=True) + (d / "kb" / "user").mkdir(parents=True) + (d / "input").mkdir() + (d / "spec" / "analyzer.seq").write_bytes(SEQ.encode()) + (d / "spec" / "main.nlp").write_bytes(main.encode()) + kbb = eol.join(["verbs", " buy: k=v1"]) + eol + (d / "kb" / "user" / "verbs.kbb").write_bytes(kbb.encode()) + return d + + def result(self, d): + found = list(d.rglob("result.txt")) + return found[0].read_text().strip() if found else None + + def test_syntax_error_raises_with_the_pass_error(self): + self.make("broken", BAD) + with self.assertRaises(NLPPlus.AnalyzerError) as cm: + self.engine.analyze("Hello.", "broken") + self.assertEqual(cm.exception.analyzer_name, "broken") + self.assertIn("2 2 [Syntax error.]", str(cm.exception)) + self.assertNotIn("\x00", str(cm.exception)) + # Caught by code that handles ordinary errors. + self.assertIsInstance(cm.exception, Exception) + + def test_the_engine_works_after_a_failed_load(self): + self.make("broken", BAD) + self.make("good", GOOD) + with self.assertRaises(NLPPlus.AnalyzerError): + self.engine.analyze("Hello.", "broken") + self.engine.analyze("Hello.", "good") + self.assertEqual(self.result(self.work / "analyzers" / "good"), + "verbs=verbs k=v1") + # And a second try still fails rather than reusing a stale build. + with self.assertRaises(NLPPlus.AnalyzerError): + self.engine.analyze("Hello.", "broken") + + def test_missing_analyzer_raises(self): + with self.assertRaises(NLPPlus.AnalyzerError): + self.engine.analyze("Hello.", "no-such-analyzer") + + def test_compile_of_a_broken_analyzer_raises(self): + self.make("broken", BAD) + with self.assertRaises(NLPPlus.AnalyzerError): + self.engine.compile("broken", analyzer_only=True) + + def test_logs_are_written(self): + d = self.make("good", GOOD) + self.engine.analyze("Hello.", "good") + self.assertTrue((d / "logs" / "make_ana.log").is_file()) + + # Linux and macOS kept the CR of every line until nlp-engine 4.2.52. + @unittest.skipUnless(engine_at_least(4, 2, 52), "needs nlp-engine 4.2.52") + def test_crlf_kbb_loads(self): + d = self.make("crlf", GOOD, eol="\r\n") + self.engine.analyze("Hello.", "crlf") + self.assertEqual(self.result(d), "verbs=verbs k=v1") + + +if __name__ == "__main__": + unittest.main()