mirror of
https://github.com/paperless-ngx/paperless-ngx.git
synced 2026-08-26 20:53:20 +00:00
revert: log every search misconfiguration, not one per field
This reverts ea883f416, which suppressed repeat MISCONFIGURED logs to once per field per process. A misconfigured field is a static condition an operator can fix in one change, so the repetition is the prompt to fix it rather than noise to suppress, and it stops on its own once the schema is corrected. Keeping the suppression meant carrying machinery whose key boundedness and check-then-add race both had to be reasoned about, to solve a problem that ends when someone fixes the config. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
This commit is contained in:
co-authored by
Claude Opus 5
parent
4de3711940
commit
3f6af15f7d
@@ -133,35 +133,6 @@ def _user_facing_emit_message(d: Diagnostic) -> str:
|
||||
return "The search query could not be executed."
|
||||
|
||||
|
||||
# MISCONFIGURED reports a static configuration fact (the registry declares a
|
||||
# field the schema does not carry, or one that is not fast), so it stays true
|
||||
# until an operator changes the schema and reindexes. The operator-facing log
|
||||
# therefore fires once per (kind, field) per process: an alert that repeats on
|
||||
# every user query is one operators learn to filter out. A restart re-logs,
|
||||
# which re-surfaces the condition after a config change.
|
||||
#
|
||||
# Bounded by the registry, not by query text: emit() only reports MISCONFIGURED
|
||||
# for a field it resolved, and FieldRegistry.resolve returns None for any name
|
||||
# or JSON subpath the registry does not declare (those become AST_UNKNOWN_FIELD,
|
||||
# an INTERNAL cause that never reaches here), so a user cannot grow this set.
|
||||
_logged_misconfigurations: set[tuple[DiagnosticKind, str]] = set()
|
||||
|
||||
|
||||
def _log_misconfiguration_once(d: Diagnostic) -> None:
|
||||
"""Log a registry/schema mismatch the first time this process sees it for
|
||||
a given field. Never gates the 400: every request still gets its answer."""
|
||||
key = (d.kind, str(d.field))
|
||||
if key in _logged_misconfigurations:
|
||||
return
|
||||
_logged_misconfigurations.add(key)
|
||||
logger.error(
|
||||
"Search index misconfiguration for field %s (%s): %s",
|
||||
d.field,
|
||||
d.kind.name,
|
||||
d.message,
|
||||
)
|
||||
|
||||
|
||||
def _map_emit_error(e: QueryError) -> SearchQueryError:
|
||||
"""Route an emit-time QueryError by its Diagnostic's Cause.
|
||||
|
||||
@@ -171,15 +142,19 @@ def _map_emit_error(e: QueryError) -> SearchQueryError:
|
||||
re-raised to surface the same way views.py already lets QueryParserError
|
||||
surface. MISCONFIGURED is deliberately both: the registry and the index
|
||||
schema disagree, which only an operator can fix, so it is logged as an
|
||||
error (once per field per process, see _log_misconfiguration_once), but a
|
||||
request is still waiting and the query cannot run either way, so it also
|
||||
returns a 400.
|
||||
error, but a request is still waiting and the query cannot run either
|
||||
way, so it also returns a 400.
|
||||
"""
|
||||
d = e.diagnostic
|
||||
if d.cause is Cause.INTERNAL:
|
||||
raise e
|
||||
if d.cause is Cause.MISCONFIGURED:
|
||||
_log_misconfiguration_once(d)
|
||||
logger.error(
|
||||
"Search index misconfiguration for field %s (%s): %s",
|
||||
d.field,
|
||||
d.kind.name,
|
||||
d.message,
|
||||
)
|
||||
return SearchQueryError(_user_facing_emit_message(d))
|
||||
|
||||
|
||||
|
||||
@@ -8,7 +8,6 @@ from __future__ import annotations
|
||||
|
||||
import logging
|
||||
from datetime import UTC
|
||||
from typing import TYPE_CHECKING
|
||||
|
||||
import pytest
|
||||
import tantivy
|
||||
@@ -20,30 +19,17 @@ from whoosh_compat.fields import FieldKind
|
||||
from whoosh_compat.fields import FieldRef
|
||||
|
||||
from documents.search._errors import SearchQueryError
|
||||
from documents.search._query import _logged_misconfigurations
|
||||
from documents.search._query import _map_emit_error
|
||||
from documents.search._query import _single_diagnostic_to_error
|
||||
from documents.search._query import parse_user_query
|
||||
from documents.search._schema import build_schema
|
||||
from documents.search._tokenizer import register_tokenizers
|
||||
|
||||
if TYPE_CHECKING:
|
||||
from collections.abc import Iterator
|
||||
|
||||
pytestmark = pytest.mark.search
|
||||
|
||||
_LIBRARY_PROSE = "INTERNAL LIBRARY WORDING WITH raw tantivy detail"
|
||||
|
||||
|
||||
@pytest.fixture(autouse=True)
|
||||
def _forget_logged_misconfigurations() -> Iterator[None]:
|
||||
"""The MISCONFIGURED log dedupes per process, so each test starts from a
|
||||
process that has never seen one."""
|
||||
_logged_misconfigurations.clear()
|
||||
yield
|
||||
_logged_misconfigurations.clear()
|
||||
|
||||
|
||||
@pytest.fixture(scope="module")
|
||||
def query_index() -> tantivy.Index:
|
||||
"""An in-memory, unstemmed index; these tests only parse, never index."""
|
||||
@@ -246,75 +232,3 @@ class TestRealQueriesRouteCorrectly:
|
||||
monkeypatch.setattr(query_mod, "tantivy_emit", raise_internal)
|
||||
with pytest.raises(QueryError):
|
||||
parse_user_query(query_index, "invoice", UTC)
|
||||
|
||||
|
||||
class TestMisconfigurationLogIsDeduped:
|
||||
"""The operator alert fires once per field per process; the 400 never is.
|
||||
|
||||
An alert that repeats on every user query is one operators filter out,
|
||||
and EXISTS_REQUIRES_FAST is reachable from ordinary query text.
|
||||
"""
|
||||
|
||||
def test_repeated_query_logs_once_but_400s_every_time(
|
||||
self,
|
||||
query_index: tantivy.Index,
|
||||
caplog: pytest.LogCaptureFixture,
|
||||
) -> None:
|
||||
with caplog.at_level(logging.ERROR, logger="paperless.search"):
|
||||
for _ in range(3):
|
||||
with pytest.raises(SearchQueryError) as excinfo:
|
||||
parse_user_query(query_index, "notes.user:*", UTC)
|
||||
assert "notes.user" in str(excinfo.value)
|
||||
assert len([r for r in caplog.records if r.levelno == logging.ERROR]) == 1
|
||||
|
||||
def test_a_different_field_still_logs(
|
||||
self,
|
||||
query_index: tantivy.Index,
|
||||
caplog: pytest.LogCaptureFixture,
|
||||
) -> None:
|
||||
"""What stops a naive log-once-ever implementation passing."""
|
||||
with caplog.at_level(logging.ERROR, logger="paperless.search"):
|
||||
for query in ("notes.user:*", "notes.user:*", "custom_fields.value:*"):
|
||||
with pytest.raises(SearchQueryError):
|
||||
parse_user_query(query_index, query, UTC)
|
||||
logged = [r.getMessage() for r in caplog.records if r.levelno == logging.ERROR]
|
||||
assert len(logged) == 2
|
||||
assert any("notes.user" in m for m in logged)
|
||||
assert any("custom_fields.value" in m for m in logged)
|
||||
|
||||
def test_the_same_field_under_a_different_kind_still_logs(
|
||||
self,
|
||||
caplog: pytest.LogCaptureFixture,
|
||||
) -> None:
|
||||
"""The key is (kind, field): two distinct misconfigurations of one
|
||||
field are two distinct things for an operator to fix."""
|
||||
field = FieldRef("notes", "user")
|
||||
with caplog.at_level(logging.ERROR, logger="paperless.search"):
|
||||
for kind in (
|
||||
DiagnosticKind.EXISTS_REQUIRES_FAST,
|
||||
DiagnosticKind.EXISTS_REQUIRES_FAST,
|
||||
DiagnosticKind.SCHEMA_FIELD_MISSING,
|
||||
):
|
||||
_map_emit_error(
|
||||
QueryError(
|
||||
_diagnostic(kind, field=field, field_kind=FieldKind.JSON),
|
||||
),
|
||||
)
|
||||
assert len([r for r in caplog.records if r.levelno == logging.ERROR]) == 2
|
||||
|
||||
def test_the_dedupe_key_is_bounded_by_the_registry(
|
||||
self,
|
||||
query_index: tantivy.Index,
|
||||
) -> None:
|
||||
"""Query text cannot grow the set: a JSON subpath the registry does not
|
||||
declare never resolves, so it never reaches the MISCONFIGURED branch
|
||||
(it demotes to an unfielded text search instead)."""
|
||||
for suffix in ("aaa", "bbb", "ccc"):
|
||||
parse_user_query(query_index, f"notes.{suffix}:*", UTC)
|
||||
assert _logged_misconfigurations == set()
|
||||
|
||||
with pytest.raises(SearchQueryError):
|
||||
parse_user_query(query_index, "notes.user:*", UTC)
|
||||
assert _logged_misconfigurations == {
|
||||
(DiagnosticKind.EXISTS_REQUIRES_FAST, "notes.user"),
|
||||
}
|
||||
|
||||
Reference in New Issue
Block a user