diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 7a9cca5f3..eef7b84ad 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -132,6 +132,7 @@ jobs: python tests/test_portability.py python tests/test_training.py python tests/test_example_server_limits.py + python tests/test_example_server_errors.py - name: Email cleaning tests run: python tests/test_email.py diff --git a/examples/server.py b/examples/server.py index ed8428080..d68f07ac9 100644 --- a/examples/server.py +++ b/examples/server.py @@ -30,6 +30,7 @@ import argparse import base64 import json +import logging import os import re import time @@ -60,6 +61,11 @@ MAX_QUESTIONS = getattr(_laya_serve, "MAX_QUESTIONS", 64) MAX_STATE_CHARS = getattr(_laya_serve, "MAX_STATE_CHARS", 50_000) +# The demo answers failures the way laya.serve does: a fixed message to the caller, the +# traceback to this logger. Without it a 500 arrived as a bare status line in the server +# output and the cause had to be reproduced in-process to be found at all. +_log = logging.getLogger("laya.example-server") + # --------------------------------------------------------------------------- # # Request / response models # --------------------------------------------------------------------------- # @@ -275,8 +281,11 @@ def predict(req: PredictRequest) -> Dict[str, Any]: raise except (KeyError, ValueError) as exc: raise HTTPException(status_code=422, detail=str(exc)) from exc - except Exception as exc: # inference failure - raise HTTPException(status_code=500, detail=f"{type(exc).__name__}: {exc}") from exc + except Exception: # inference failure -- the policy laya.serve follows: the caller + # gets a fixed message, never the exception text, which describes the deployment + # (paths, libraries, memory) rather than the request. + _log.exception("prediction failed") + raise HTTPException(status_code=500, detail="prediction failed") @app.post("/predict/batch") @@ -290,8 +299,9 @@ def predict_batch(req: BatchRequest) -> Dict[str, Any]: results.append( _predict(state, questions, model=req.model, task=req.task, lang=req.lang) ) - except Exception as exc: - results.append({"index": i, "error": f"{type(exc).__name__}: {exc}"}) + except Exception: # the index names the item; the cause stays in the log + _log.exception("prediction failed for batch item %d", i) + results.append({"index": i, "error": "prediction failed"}) return {"count": len(results), "results": results} @@ -3358,8 +3368,9 @@ async def gui_predict(request: Request) -> HTMLResponse: model=req.model, task=req.task, lang=req.lang, ) res["_elapsed"] = time.perf_counter() - started - except Exception as exc: - return _gui_error("Prediction failed", [f"{type(exc).__name__}: {exc}"], + except Exception: + _log.exception("prediction failed (gui)") + return _gui_error("Prediction failed", ["The server could not complete this prediction."], "Nothing was answered. The server log has the full trace.") answers = res.get("answers") or {} diff --git a/laya/serve.py b/laya/serve.py index 2cd309228..a2bdee231 100644 --- a/laya/serve.py +++ b/laya/serve.py @@ -384,7 +384,11 @@ async def _systemone_inner(request: Request): # this the container logs show only the 500, so a deterministic failure such as a # missing C compiler for triton's JIT (#365) is invisible from the running server # and has to be reproduced in-process to be diagnosed at all. - _log.exception("inference failed for model=%s", model) + # `model` is caller-supplied text. `_resolve_model` has already reduced it to a + # shipped checkpoint name or None, and the line breaks are replaced so a crafted + # value cannot forge log entries (py/log-injection) if that ever stops holding. + _log.exception("inference failed for model=%s", + str(model).replace("\n", "\\n").replace("\r", "\\r")) raise HTTPException(status_code=500, detail="inference failed") return app diff --git a/tests/test_example_server_errors.py b/tests/test_example_server_errors.py new file mode 100644 index 000000000..6dfc99f7f --- /dev/null +++ b/tests/test_example_server_errors.py @@ -0,0 +1,139 @@ +"""Regression: examples/server.py must not echo exception text to a caller. + +`laya/serve.py` answers an inference failure with a fixed 500 (`"inference failed"`) and +keeps the cause in the log -- see `test_inference_failure_is_logged_and_not_leaked` in +tests/test_serve.py, which is where that policy is asserted. The demo server did the +opposite on all three surfaces: `f"{type(exc).__name__}: {exc}"` was returned by +`/predict`, by `/predict/batch` in its per-item `error` field, and rendered into the +`/gui` error page. Exception text names paths, libraries and memory sizes -- it describes +the deployment, not the request -- and code scanning flags it as stack-trace exposure +(py/stack-trace-exposure). + +Scope: an unexpected failure. A 4xx stays as it was: those messages name the question or +the field to fix and are meant for the caller (`/predict` answers 422 with the reason, and +the GUI lists one line per validation error). + +The router is replaced with one that raises, so no weights are needed and the failure is +deterministic. The exception carries marker text that must reach the log and must not +appear in any response. + +Run: python tests/test_example_server_errors.py +""" +import json +import logging +import os +import sys + +os.environ.setdefault("TOKENIZERS_PARALLELISM", "false") +os.environ.setdefault("LAYA_PRELOAD", "0") + +ROOT = os.path.dirname(os.path.dirname(os.path.abspath(__file__))) +sys.path.insert(0, ROOT) +sys.path.insert(0, os.path.join(ROOT, "examples")) + +PASS, FAIL = [], [] + + +def ok(name, cond, detail=""): + (PASS if cond else FAIL).append("%s%s" % (name, (" -- " + detail) if detail and not cond else "")) + print(" %s %s%s" % ("PASS" if cond else "FAIL", name, (" " + detail) if detail and not cond else ""), flush=True) + + +# The shape of the real failure this policy exists for (#365): triton's JIT with no +# compiler, naming a virtualenv path. Nothing here may reach a response. +SECRET = ("Failed to find C compiler. Please specify via CC environment variable or set " + "triton.knobs.build.impl (/opt/venv/lib/python3.11/site-packages/triton)") +LEAKS = ("C compiler", "/opt/venv", "site-packages", "triton", "RuntimeError") + + +class ExplodingRouter: + """Only what the demo calls: predict, plus the `loaded` list health reports.""" + + loaded = ["english"] + + def predict(self, state, questions, **kw): + raise RuntimeError(SECRET) + + +class Collect(logging.Handler): + """Records, for the assertion that the cause reached the log.""" + + def __init__(self): + super().__init__() + self.records = [] + + def emit(self, record): + self.records.append(record) + + +def main(): + try: + from fastapi.testclient import TestClient + except ImportError as exc: + if (getattr(exc, "name", None) or "").split(".")[0] not in ("fastapi", "httpx", "starlette"): + raise + print("SKIP: fastapi/httpx not installed -- pip install laya[serve] httpx") + return 0 + try: + import server as demo + except ImportError as exc: + if (getattr(exc, "name", None) or "").split(".")[0] not in ("fastapi", "httpx", "starlette", "multipart"): + raise + print("SKIP: examples/server.py needs the serve extra -- pip install laya[serve]") + return 0 + + # The lifespan (which builds a real Router) is not entered: TestClient without a + # `with` block leaves the app unstarted, so the stub below is what `_predict` finds. + demo.ROUTER = ExplodingRouter() + client = TestClient(demo.app, raise_server_exceptions=False) + + handler = Collect() + logger = logging.getLogger("laya.example-server") + logger.addHandler(handler) + logger.setLevel(logging.ERROR) + + one = {"a": {"type": "noul", "instructions": "x"}} + + # --- /predict: a bare 500, and no exception text in it ------------------ + r = client.post("/predict", json={"state": "hi", "questions": one}) + ok("a failed /predict is a 500", r.status_code == 500, str(r.status_code)) + ok("it answers the fixed message", r.json() == {"detail": "prediction failed"}, r.text[:200]) + ok("no exception text reaches the caller", + not any(s in r.text for s in LEAKS), r.text[:200]) + + # --- /predict/batch: per-item, the index identifies it ------------------- + r = client.post("/predict/batch", json={"states": ["hi", "ho"], "questions": one}) + errors = [item.get("error") for item in (r.json().get("results") or [])] + ok("a failed batch item reports the fixed message", + r.status_code == 200 and errors == ["prediction failed", "prediction failed"], repr(errors)) + ok("no exception text reaches a batch caller", + not any(s in r.text for s in LEAKS), r.text[:200]) + + # --- /gui: the page says what happened, not what raised ------------------ + r = client.post("/gui", json={"state": "hi", "questions": one}) + ok("a failed /gui is an error page", r.status_code == 200 and "Prediction failed" in r.text) + ok("the page carries no exception text", + not any(s in r.text for s in LEAKS), r.text[:400]) + + # --- the cause is in the log, traceback included ------------------------- + causes = [r.exc_info[1] for r in handler.records if r.exc_info] + ok("each failure logged its cause with a traceback", + len(causes) == 4, "%d records, %d with exc_info" % (len(handler.records), len(causes))) + ok("the logged cause is the real exception", + all(str(c) == SECRET for c in causes), str(causes[:1])[:200]) + + # --- a 4xx is the caller's mistake and keeps its message ----------------- + # The fix must not swallow what a caller needs to correct a request. + r = client.post("/predict", json={"state": "hi", + "questions": {"a": {"type": "bogus", "instructions": "x"}}}) + ok("a validation error is still 422 with its reason", + r.status_code == 422 and "bogus" in r.text, "%s %s" % (r.status_code, r.text[:200])) + + print("\n%d passed, %d failed" % (len(PASS), len(FAIL))) + for f in FAIL: + print(" FAIL " + f) + return 1 if FAIL else 0 + + +if __name__ == "__main__": + sys.exit(main())