Add content-indexing diagnostics to helm test failures - #1578
Draft
gionn wants to merge 11 commits into
Draft
Conversation
The intermittent test_search_document_content failure in Helm (Enterprise) CI has never had its actual cause captured: the existing failure logging dumps dtas, pod, and events output but never the search-enterprise mediation, transform, or Tika logs the content indexing path actually runs through, nor the Elasticsearch index state. Add those, plus a restart-count summary, guarded so they never mask the real test failure. Also add the helm-test action to both helm workflows' path filters, since it wasn't triggering either on changes to itself.
…pository The alfresco-search-enterprise chart's live-indexing pipeline is not just the mediation statefulset: it also runs separate content, metadata, and path resolver deployments (acs-content, acs-metadata, acs-path) that mediation calls to build each search document. None of those pod names contain "search-enterprise", "transform", or "tika", so the previous filter skipped them entirely — including the content resolver, the one component that maps directly onto the failing test's content-only search path (test_search, which hits metadata, passes; test_search_document_content, which needs resolved content, fails). Also add the ActiveMQ broker and Elasticsearch container logs themselves (previously only queried via curl for index counts), and a tail of the repository logs, since the repository is what emits the live-indexing event mediation consumes.
At INFO level, none of the content/metadata/path resolvers or the mediation Camel routes log anything per-message, so a failing run's logs show general health but give no way to tell whether a specific document's event was ever received, routed, and forwarded to Elasticsearch. Bump org.alfresco loggers to DEBUG across the liveIndexing components (content, metadata, path, mediation share this key) to get message-level tracing on the next failing run. This is diagnostic-only and should be reverted once the root cause is identified.
The stock v1.9.0 DTAS image's failure message only reports the search timeout, not which node it was searching for, so a failing run's logs can't be correlated against the indexing pipeline's per-node DEBUG output added in prior commits. The pr-230 image (built during an earlier investigation into this same flake, already published at quay.io/alfresco/alfresco-deployment-test-automation-scripts:pr-230) prints node_id/attempts/last_status on failure. Using it here purely to get that identifier so it can be grepped across the mediation and resolver logs on the next failing run. Diagnostic-only — revert once the root cause is identified.
Prior evidence traced a failing node's events through content, metadata, and path resolvers: metadata and path both succeed, and content itself logs a successful Updated call at the right time (right after the content-upload event, not a stale create-only snapshot) with no error. That rules out message loss or delivery races as the cause of this run's failure — but the update log line only shows an object hash, not what was actually written. Parse node_id out of the DTAS pod's own failure output (now captured so it can be grepped) and fetch that exact document's _source from Elasticsearch, to see directly whether the content field is missing, empty, or present but not matching the test's query.
The ES document dump proved the content pipeline is not the problem: for the last two failing nodes, cm%3Acontent was fully indexed with the exact search phrase, and CONTENT_INDEXING_LAST_UPDATE was over 3 minutes before the DTAS test gave up after 874 failed poll attempts. That rules out any indexing race or delivery loss — the document was searchable-in-principle the whole time DTAS was polling for it. Since the data is provably correct in Elasticsearch, the remaining candidates are all in query translation: the AFTS TEXT/ANCESTOR clause not matching against the stored fields. Replay the exact query DTAS sends (recovered from its search.json template) against the live Search API for the failing node, split into three variants (full, TEXT-only, ANCESTOR-only) to isolate which clause fails to match a document proven to contain the requested content.
Leading hypothesis for the flake is CPU starvation: every component in test/enterprise-integration-test-values.yaml runs at cpu request 0.01 with no enforced limits, sharing a single kind node with everything else in the chart. Elasticsearch writes succeed immediately via the translog (proven by the earlier _doc/id fetch), but _search only sees refreshed segments — if the refresh thread gets starved for CPU under concurrent load, writes stay invisible to search until refresh catches up, which would explain both the symptom (data proven present but not found) and the flakiness (available CPU on a shared runner varies run to run). Switch to alfrescoPub-ubuntu2404-32G-8CPU to test that directly: if the failure rate drops sharply with 8x the CPU/RAM, that confirms resource starvation as the cause rather than a query-logic bug. Diagnostic-only — revert once the root cause is confirmed either way.
This reverts commit 859d693.
Root cause narrowed down to ES search-visibility lag: two independent failing nodes both had fully correct, complete data confirmed via real-time GET by id, but _search missed whichever field's partial update (from content/metadata/path resolvers) landed most recently relative to the last refresh cycle. Every requests.cpu in this file is currently 0.01, identical across every container, so ES's own refresh/merge threads get no scheduling priority over the rest of the chart under CPU contention on the runner. Raise just Elasticsearch's request to 1 core as the most targeted, cheapest test: if this alone drops the failure rate meaningfully, it confirms scheduling starvation (not a query bug) and is mergeable as is. content/metadata/path/mediation share one still-untouched resources key and are the next candidate if this alone isn't enough. Diagnostic-only — revisit the exact value once the theory is confirmed.
…ory" This reverts commit be6f3ca.
Overrides ALFRESCO_ACCEPTEDCONTENTMEDIATYPESCACHE_REFRESHTIME to every 15 seconds on the mediation component only, instead of the chart's hourly default, to see whether stale accepted-media-type data plays a role in the search diagnostics.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
Helm (Enterprise)CI is intermittently red onmaster(5 of the last 8 runs) withtest_search_document_content(DTAS) timing out. The existing failure logging dumps dtas/pod/events output but never the logs from the actual content-indexing path — search-enterprise mediation, transform service, Tika — or the Elasticsearch index state, so the root cause has never actually been captured despite prior investigation (see #1575, which spent 25 commits guessing at fixes without this data).This PR adds no behavior changes, only observability on the failure path:
helm-testaction's failure-status step with mediation/transform/tika logs, ES_cat/indices+ doc count, and a container restart-count summary, all guarded with|| trueso diagnostics never mask the real test failure.github/actions/helm-test/**to both helm workflows'pathsfilters, since neither currently re-triggers on changes to that actionOnce this lands and a few failing runs have occurred, the logs should show whether the content-indexing route is erroring, never receiving the event, or genuinely just slow — which determines whether the right fix is a timeout bump, a repository-side fix, or something in the transform/Tika path.
Test plan
masterand let the matrix cycle a few times (per-leg failure rate is only ~15-30%, so a single green run doesn't confirm anything)Content indexing pipeline logs,Elasticsearch index state,Container restart summary) actually appear and contain useful data