UN-3016 [FIX] Record why an execution failed; stop dispatching skipped files - #2256
UN-3016 [FIX] Record why an execution failed; stop dispatching skipped files#2256hari-kuriakose wants to merge 7 commits into
Conversation
…d files A customer (Moody's) execution ended in ERROR with no explanation. Verified against the prod row for 30b84e4a-8675-4e93-a235-8d5dbac89be8: status=ERROR, error_message='' (blank), total_files=1. Three distinct defects, fixed here: 1. Execution errors were recorded blank. _determine_execution_status_unified() decided ERROR purely from failure counts and returned no reason, so all three call sites passed error_message=None. WorkflowExecution.update_execution() guards on `if error:`, so error_message was never written. It now returns a reason summarised from the per-file errors already present in aggregated_results, capped to the CharField(256) that otherwise truncates silently. 2. A file skipped for an unsupported MIME type was still handed to a worker. The skip deliberately never wrote the file's bytes, but returned it with is_executed=True and a "temp-hash-<uuid>" sentinel. Nothing downstream filters on is_executed, so a worker ran, failed on the missing file, and produced the opaque "Execution: <path>; Destination: <path>" error seen in the incident row (that string is built by interpolating two FileNotFoundError paths, not by mangling a MIME message). Skipped files are now excluded from the staged set; if every file is skipped the request fails with a 400 naming the unsupported types instead of dispatching an empty execution. 3. The workers' AllowedFileTypes lacked XLSM while the backend had it. The two MIME lists are now identical, so a file the API accepts cannot be rejected again inside the worker. Tests: workers/tests/test_un3016_execution_error.py, 9 passing — covers the real incident error shape, the never-blank guarantee, the 256-char column fit, and a regression guard that no caller reintroduces error_message=None. Note: XLSM was absent from the backend enum at the time of the incident and has since been added, so the customer's .xlsm would be accepted today; the defects above remain for any other unsupported type.
for more information, see https://pre-commit.ci
Remediation of review findings on PR #2256. F1 (High): the new UnsupportedMimeTypeError raised by add_input_file_to_api_storage escaped the try/except in WorkflowViewSet.execute that owns delete_api_storage_dir, so a partial stage could leave written files behind. The staging call now has its own handler mirroring the one at the end of the method. The sibling caller (api_v2/deployment_helper.py:279) was already guarded. F2 (High): test_no_caller_passes_a_hardcoded_none_error asserted "error_message=None" not in the whole 1900-line tasks.py. It matched nothing at the sites it meant to guard and would trip on any unrelated keyword default. Now an AST check scoped to _process_batch_callback_core and process_batch_callback_api. Mutation-checked: reintroducing error_message=None at process_batch_callback_api fails the test with that call site's line number. F4 (Medium): _EXECUTION_ERROR_MAX_LENGTH now names its authority, EXECUTION_ERROR_LENGTH in backend workflow_v2/models/execution.py, following the convention in workflow_v2/undispatched_sweep.py. Adversarial verification also found two comments I had written asserting mechanisms the code does not have (the storage dir is a computed path, not a mkdir; the AST check does not catch positional/indirected None). Both false claims deleted rather than reworded. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01NQhqNqCwFcXZZ7cQU6HxUE
…rce shape Behaviour-preserving cleanup, run once after the review verdict settled. - views.py: drop the second cleanup handler added in the previous commit and stage inside the existing try instead. That handler's guard is exactly the staging condition, so one handler now covers both paths rather than two copies of the same contract. - test_un3016_execution_error.py: import callback.tasks directly instead of extracting the helper with ast/exec. The docstring's claim that importing pulls in an unusable celery runtime is false — conftest loads .env.test before collection, and test_pg_callback_duplicate_guard.py already imports the module at module level. Verified by running the import under pytest. test_status_function_returns_a_reason is now behavioural: it calls _determine_execution_status_unified and asserts the reason is non-blank. The old version asserted only that every return was a 4-tuple, which would have passed with an always-None fourth element — i.e. it could not detect the very defect it was named for. Mutation-checked: forcing error_message = None now fails the test. - _summarize_file_errors: errors is keyed by file name, so entries are distinct by construction and the `entry not in seen` dedup could never fire. Removed, along with the duplicate early return it guarded. - source.py: skipped_files was a dict never used as a mapping; now a list of pre-formatted entries. Tests: 1298 passed, 132 skipped. test_pg_reaper.py deselected — it needs a live Postgres on 127.0.0.1:5432 and hangs identically on unmodified HEAD. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01NQhqNqCwFcXZZ7cQU6HxUE
_determine_execution_status_unified marks ERROR from two places, and a blank error_message from either one is the UN-3016 defect. Only the failed_files == total_files branch was covered; the timeout branch (files expected, no batch result came back) had no test at all — mutating its error_message to None left the suite green. Adds test_timeout_failure_also_returns_a_reason, which mocks the api_client so get_workflow_execution reports total_files=3 with an empty file_batch_results, driving has_timeout_failure. Mutation-checked: forcing that branch's error_message to None now fails the test. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01NQhqNqCwFcXZZ7cQU6HxUE
Note: partial file skips are silent to the API caller — deliberately not fixed hereFlagged during review and waived, not overlooked. Recording the reasoning so it is stated rather than rediscovered later. The behaviour. The guard added in this PR is at if skipped_files and not file_hashes:
raise UnsupportedMimeTypeError(
"No files could be processed. Unsupported file type(s): " + ", ".join(skipped_files)
)The Why it is not fixed in this PR.
The asymmetry worth knowing about. Total failure is now loud and explicit; partial failure is quiet. That is a deliberate trade, not an oversight — but it does mean a user can get a successful run over fewer files than they uploaded without the response saying so. Suggested follow-up: report skipped files to the caller, e.g. as a Reviewed with unstract:lite-remediation; finding F3, waived. |
PR #2256's workers half had 8 tests; its backend half had none. Six tests close that gap, all DB-free (the ORM boundary and file storage are patched, so no Postgres is needed). source.py — add_input_file_to_api_storage: - partial skip returns only the supported files, and does NOT raise. A rejected file alongside a runnable one is simply absent from the mapping; the request proceeds with what can be run (UN-4055 tracks whether that should remain the behaviour, so this pins it rather than asserting a raise). - a total skip raises UnsupportedMimeTypeError naming every skipped file and its MIME type, instead of dispatching an empty execution that would report a vacuous success. - an empty request returns {} without raising: the guard is on something having been skipped, not merely on the mapping being empty. - an accepted file's FileHash carries the sha256 of the staged bytes. This is characterisation only — it held before the fix and no mutation of the fix makes it fail; it documents what a returned entry looks like, which is what makes the rejected file's absence meaningful. views.py — WorkflowViewSet.execute: - a staging failure reaches delete_api_storage_dir, so a partial stage does not leave written files behind. - a request that staged nothing does not attempt that cleanup. Files are real SimpleUploadedFile objects, not mocks: a MagicMock's content_type is never in AllowedFileTypes, so a mocked "supported" file would silently take the skip branch and the test would pass for the wrong reason. Mutation-checked, each mutation reverted and the restore verified on disk: - re-adding the rejected file to file_hashes with a temp hash -> partial-skip and total-skip tests fail - dropping "and not file_hashes" from the raise condition -> partial-skip test fails (it now raises on a request that has runnable files) - dropping "skipped_files and" from the raise condition -> empty-request test fails - deleting the raise block -> total-skip test fails - stripping the filenames from the error message -> total-skip test fails - moving staging back outside the try -> staging-failure test fails - dropping the has_uploads guard on cleanup -> no-cleanup test fails Five of the six tests are pinned by a mutation; the sha256 test is the characterisation case noted above. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01NQhqNqCwFcXZZ7cQU6HxUE
|
|
| Filename | Overview |
|---|---|
| backend/workflow_manager/endpoint_v2/source.py | Filters unsupported uploads out of the staged mapping and raises a descriptive error when no processable files remain. |
| backend/workflow_manager/workflow_v2/views.py | Moves upload staging into the existing cleanup boundary so staging failures remove execution-scoped API storage. |
| workers/callback/tasks.py | Adds bounded execution-error summaries and propagates them through both callback finalization and notification paths. |
| workers/shared/enums/file_types.py | Adds the XLSM MIME type to align worker validation with backend acceptance. |
Sequence Diagram
sequenceDiagram
participant C as API client
participant B as Backend staging
participant W as File worker
participant K as Callback
participant E as Execution record
C->>B: Upload files
B->>B: Filter unsupported MIME types
alt No supported files
B-->>C: 400 with unsupported types
else Supported files remain
B->>W: Dispatch only staged files
W-->>K: Per-file results
K->>K: Determine final status and reason
K->>E: Persist counts, status, and error message
K-->>C: Notify with failure reason when applicable
end
Reviews (1): Last reviewed commit: "Merge branch 'main' into worktree-un3016..." | Re-trigger Greptile
Unstract test resultsPer-group results
Critical paths
|
chandrasekharan-zipstack
left a comment
chandrasekharan-zipstack
left a comment
There was a problem hiding this comment.
Standardized review (FOLLOWUP) — High-severity findings only
Verdict: BLOCK — Critical 0 · High 5 · Medium 13 · Low 5 · Lenses 16/16.
This review posts only the 5 High findings. The 13 Medium and 5 Low are held back to keep the thread actionable; happy to post them on request.
Why BLOCK. The PR's three claimed fixes are (1) record a reason, (2) stop dispatching skipped files, (3) align the MIME lists. #2 works. #1 produces a content-free string in production and actively destroys better error messages that already existed. #3 is dead code. Two of the three are certified by tests that pass against shapes production never produces.
Prior round reconciled
The lite-remediation loop that produced F1–F4 never posted its findings to this thread, so the ledger below is reconstructed from commit 9e1adc4ca8's body and your waiver comment. Previous-review boundary: 9e1adc4ca8; surface added after it: af64650ca9, 1ceb723a5a, e15e3e2aad, 2c95b6a7d8.
| # | Sev | Title | Status |
|---|---|---|---|
| F1 | High | UnsupportedMimeTypeError escaped the try owning delete_api_storage_dir |
RESOLVED |
| F2 | High | Whole-file substring assertion in the caller guard test | PARTIALLY RESOLVED |
| F3 | Med | Partial skips invisible to the API caller | WAIVED (yours, in writing — UN-4055; not re-raised) |
| F4 | Med | _EXECUTION_ERROR_MAX_LENGTH did not name its authority |
PARTIALLY RESOLVED — new defect introduced |
- F1 → RESOLVED.
views.py:268-276stages inside the try;has_uploadsat:261is literally the same boolean as the cleanup guard at:297. Pinned bytest_un3016_execute_staging_cleanup.py:57. But the move is unpinned on the success side — see H5. - F2 → PARTIALLY RESOLVED. Now an AST check scoped to the two functions (
test_un3016_execution_error.py:179-191). It rejects a literalerror_message=Nonekeyword but not the mutation that actually happens — omitting the keyword, which both callees default toNone. See H4. - F4 → PARTIALLY RESOLVED, new defect. The comment now names
EXECUTION_ERROR_LENGTH(tasks.py:257-260) but cites a conventionundispatched_sweep.pydoes not implement, and omits the real second hardcoded copy atinternal_views.py:899/:904. Detail is in the held-back Mediums. - The two false comments deleted in
9e1adc4ca8— confirmed gone, not resurrected.
Cleared, contra the earlier gate
- OpenAPI needs no update. The 422 outcome is already documented with
ExecuteResponsecarryingexecution_status/error(backend/api_v2/openapi_schema.py:206-208), and 400 at:143. - The MIME lists are genuinely identical — programmatic member-for-member diff at PR head: 22 members each, zero divergence. Your claim is accurate (though see H3 — the new entry is unreachable).
- The 3→4 tuple breaks no consumer —
_determine_execution_status_unifiedis module-local; repo-wide grep plusunstract-cloudandunstract-cloud-platformfind no external unpack. - No rate-limit slot leak on the newly-hot error path. Checked specifically because this PR makes that branch routine;
zremis idempotent and the correct release already fires viaupdate_execution. - Rolling-deploy safe —
error_messageis pre-existing and optional on both the worker client and the serializer.
Bots: SonarCloud passed its gate but reports 0.0% coverage on new code, corroborating H4/H5. Greptile rated this "5/5 — safe to merge, no concrete changed-code defect remaining"; H1 and H3 contradict that directly.
Open questions
- H1 is the crux — was the
errorsmap ever observed populated? Do you have a real execution whereaggregated_results["errors"]was non-empty? Static reading andFileExecutionResult.__post_init__say it cannot be. If so, what does this PR change about the Moody's row beyond blank →"All 1 file(s) failed."? - H3 — do you have a real
.xlsmthat libmagic reports asapplication/vnd.ms-excel.sheet.macroenabled.12? The deployed worker's magic DB has nomacroenabledentry at all. If not, what does the enum line do? - H2 — is overwriting an existing
error_messageon an already-ERROR row intended? If yes it should be explicit in code; if not it is a regression this PR introduces. - Should the public API-deployment endpoint return 400 or 422 for an all-unsupported upload? The description says 400; the code delivers 422 (
deployment_helper.py:286's bareexcept Exceptionswallows theAPIException, andapi_deployment_views.py:168re-surfaces it). Both are documented, so this is a product call — but the two callers should not disagree, and the description is currently wrong. Detail in the held-back Mediums.
Process note
The working tree at /home/chandru/zipstuff/unstract was switched off this PR's branch mid-review by a concurrent process, so early reads hit pre-PR code. That was detected, an isolated worktree was built at PR head, and every citation below was re-verified. All line numbers are PR-head numbers.
| def _summarize_file_errors(aggregated_results: dict[str, Any], total_files: int) -> str: | ||
| """Build an execution-level reason from the per-file errors. | ||
|
|
||
| The execution row previously recorded ERROR with a blank error_message, | ||
| leaving users with a failed run and no explanation (UN-3016). The per-file | ||
| errors are already aggregated as {file_name: error}; surface them here. | ||
| """ | ||
| errors: dict[str, Any] = aggregated_results.get("errors") or {} | ||
| # `errors` is keyed by file name, so every entry is distinct already; the | ||
| # cap is what keeps a large batch from bloating the column. | ||
| entries = [ | ||
| f"{file_name}: {str(error).strip()}" | ||
| for file_name, error in errors.items() | ||
| if error and str(error).strip() | ||
| ] | ||
| if not entries: | ||
| return f"All {total_files} file(s) failed." |
There was a problem hiding this comment.
[High] [Lens 1, 3, 10, 13] — The error summary is a tautology in production: aggregated_results["errors"] is always empty
_summarize_file_errors reads only aggregated_results["errors"]. That map admits an entry only when file_result.get("status") == "error" (lowercase). No producer ever emits that string:
- API path —
workers/file_processing/tasks.py:1844wraps every result inFileExecutionResult, whose__post_init__(unstract/core/src/unstract/core/worker_models.py:301-305) forcesstatustoApiDeploymentResultStatus.SUCCESS/FAILED="Success"/"Failed"(worker_models.py:108-112). - ETL/TASK path —
workers/file_processing/tasks.py:1073-1081constructsBatchExecutionResultwith nofile_results=argument at all.
So errors == {} always, and :281 always returns the fallback. The Moody's incident row would now read "All 1 file(s) failed." — a restatement of status=ERROR + failed_files=1. The user still cannot see why. The blank was replaced by a near-blank.
A repo-wide grep finds no file_results producer emitting "error". The PR's own fixture hand-writes {"status": "error", ...} at workers/tests/test_un3016_execution_error.py:85-93, so test_status_function_returns_a_reason (:97) is green against a shape production cannot produce.
Fix: key on the presence of an error, not on a status string — time_utils.py:180 → if isinstance(file_result, dict) and file_result.get("error"):, keying the name off file_name or file. Separately file_processing/tasks.py:1073 must pass file_results= or the ETL path keeps summarising nothing. Then rebuild the fixture from a real FileExecutionResult(...).to_dict().
Confidence: High — verified independently against PR-head source.
| aggregated_results=aggregated_results, | ||
| organization_id=context.organization_id, | ||
| error_message=None, | ||
| error_message=status_error, |
There was a problem hiding this comment.
[High] [Lens 3, 6, 10] — The tautology now overwrites specific error messages that previously survived
Both backend writers — backend/workflow_manager/workflow_v2/models/execution.py:467 and :496 — apply if error: self.error_message = error[:EXECUTION_ERROR_LENGTH] unconditionally, and backend/workflow_manager/internal_views.py:570-573 documents that "ERROR is deliberately NOT protected."
Before this PR the callback passed error_message=None, so if error: was false and any earlier specific message survived. Now a late callback overwrites it.
Concrete sequence: the orchestrator writes a real cause, or update_execution_err records the staging cause; the batch callback then fires and replaces it with "All 2 file(s) failed.". Combined with H1 this is a net regression against this PR's own goal — a row that had a real diagnostic ends up with a tautology.
Same applies at :1799.
Fix: don't write error_message when the row already carries one (if error and not self.error_message:), or have the callback pass its summary only when the fetched execution's error_message is blank — _determine_execution_status_unified already fetches the execution at :344-359, so the current value is one field away. If overwrite is intended, say so in code.
Confidence: High on mechanism; Medium on frequency.
| # Kept in step with the backend's AllowedFileTypes (UN-3016): the two lists | ||
| # must agree or a file the API accepts is rejected again inside the worker. | ||
| XLSM = "application/vnd.ms-excel.sheet.macroenabled.12" |
There was a problem hiding this comment.
[High] [Lens 1, 3, 13, 16] — This XLSM enum addition is dead code — defect #3 is not fixed
Two independent reasons the new member can never fire:
1. Wrong path. The only AllowedFileTypes.is_allowed call in workers/ is shared/workflow/execution/service.py:1226, inside _copy_filesystem_file (:1160). The API path is _copy_api_file (:1104-1157) and performs no MIME validation at all. So the comment's claim — "a file the API accepts is rejected again inside the worker" — describes a rejection that cannot occur.
2. Wrong MIME source. On the filesystem path the type comes from magic.from_buffer(chunk, mime=True) (service.py:1223) — content sniffing, not the client header the backend trusts (source.py:1233). libmagic's database has no macroenabled entry. Verified inside the running worker container: all three of /usr/share/misc/magic.mgc, /usr/lib/file/magic.mgc, /usr/share/file/magic.mgc report macroenabled=0 while spreadsheetml=1. A macro-enabled workbook sniffs as application/vnd.openxmlformats-officedocument.spreadsheetml.sheet — already allowed before this PR.
Also: zero tests reference AllowedFileTypes behaviourally anywhere in workers/tests, backend/**/tests, or tests/.
Fix: drop the change, or justify it with a real .xlsm fixture driven through magic.from_buffer. Correct the comment and the PR description's defect #3. If the lists genuinely must stay in lockstep, add a value-set equality test (it passes today — 22 members each, zero divergence).
Confidence: High — verified in the deployed worker image, not a synthetic fixture.
| pipeline_name=context.pipeline_name, | ||
| pipeline_type=context.pipeline_type, | ||
| error_message=None, | ||
| error_message=status_error, |
There was a problem hiding this comment.
[High] [Lens 13 — Testing] — The entire caller-side half of the fix is unpinned: deleting all four error_message=status_error sites keeps CI green
The user-visible half of UN-3016 is "the execution row and the webhook payload carry a reason." Nothing tests that threading. Both callees default the parameter (tasks.py:417, :635), so a refactor dropping the kwarg silently restores the exact defect — ERROR status, blank error_message, webhook with no reason — with CI green.
Mutation executed. Deleting lines 1538, 1593, 1799 and 1860 → the new file gives 10 passed; six callback-adjacent suites give 92 passed.
The AST guard at test_un3016_execution_error.py:153-191 only rejects a literal error_message=None keyword; an omitted keyword contributes no entry to call.keywords. Its docstring enumerates the evasions it misses — positional-None, indirection, **kwargs splat — but not "delete the keyword," which is the one that actually happens.
Fix: one behavioural test per entry point driving _process_batch_callback_core / process_batch_callback_api with an all-failed batch, asserting api_client.update_workflow_execution_status.call_args.kwargs["error_message"] and the notification call both carry the summary. That kills all four mutations and makes the AST guard redundant.
Confidence: High (mutation executed).
| if has_uploads: | ||
| hashes_of_files = SourceConnector.add_input_file_to_api_storage( | ||
| pipeline_id=pipeline_guid, | ||
| workflow_id=workflow_id, | ||
| execution_id=execution_id, | ||
| file_objs=file_objs, | ||
| use_file_history=False, | ||
| ) | ||
| workflow = self.get_workflow_by_id(workflow_id=workflow_id) |
There was a problem hiding this comment.
[High] [Lens 13 — Testing] — The staging move is unpinned against dropping the staged hashes
Both tests in test_un3016_execute_staging_cleanup.py (:57, :77) raise before execute_workflow is reached, so nothing asserts the staged hashes still flow through.
Losing this assignment dispatches an execution with hash_values_of_files={} — the run reports success having processed zero uploaded files. A silent correctness failure on the primary upload flow.
Mutation executed. Changing :269 to drop only the assignment → 2 passed. No other test exercises WorkflowViewSet.execute().
Fix: a third test asserting execute_workflow.call_args.kwargs["hash_values_of_files"] is the sentinel returned by staging, and that use_file_history is False.
Confidence: High (mutation executed).
2 participants
UN-3016 — an execution failed with no explanation
A customer (Moody's) execution ended in ERROR with nothing telling the user why. Root-caused from code and then corroborated against the actual prod row:
ERROR...Application.xlsm(application/vnd.ms-excel.sheet.macroenabled.12)temp-hash-9d260345dd444238a58eb42ab562bcd7The prod logs for this run are long gone (30-day retention vs a 283-day-old incident), so the DB row is the evidence.
What was happening
The
temp-hash-prefix is written in exactly one place — the backend MIME-skip branch — which pins the mechanism:.xlsmand took the skip branch, which deliberately never writes the file's bytes. But it returned the file withis_executed=Trueand a fake hash.is_executed, so the file was counted intotal_filesand dispatched to a worker anyway.FileNotFoundError(path)stringifies to.failed_files == total_files(1 == 1) escalated the execution to ERROR._determine_execution_status_unifiedreturned only a status and counts — no reason string — so every call site passederror_message=None.WorkflowExecution.update_execution()guards onif error:, soerror_messagewas never written.Verified present at
0da9da5a8, the commit that was HEAD the day the ticket was filed — pre-existing, not a regression.Changes
_determine_execution_status_unifiedreturns a reason built from the per-file errors already aggregated inaggregated_results; all call sites pass it through, including notifications. Capped to theCharField(256)that otherwise truncates silently.AllowedFileTypeswas missing XLSM while the backend had it. The two MIME lists are now identical, so a file the API accepts cannot be rejected again inside the worker.PGMQ
All three apply to the PGMQ stack. It is not a separate callback path — it shares
_process_batch_callback_coreandprocess_batch_callback_apiwithis_pgas a kwarg flag, so both patched call sites cover it. Staging is backend-side and transport-agnostic, and the PG stack has no MIME list of its own. Its own error paths ([pg-poison-drop],[pg-barrier-abort],[reaper-recovery]) already wrote descriptive reasons and never had this defect.Tests
workers/tests/test_un3016_execution_error.py— 9 passing: the real incident error shape, the never-blank guarantee, the 256-char column fit, and a regression guard that no caller reintroduceserror_message=None.Reviewer notes
unstract.corepackage, absent from this checkout. The 3→4 tuple change on_determine_execution_status_unifiedis the thing to watch; the two PG tests touching it mock withassert_not_called, so they should be unaffected, but CI is the real check.FileNotFoundErrorpaths. This PR makes the execution record it rather than a blank — an improvement, not a cure._handle_null_execution_resultalso still publishes nothing to the UI; proven not to be this incident's mechanism, so left alone. Both warrant a follow-up.🤖 Generated with Claude Code
https://claude.ai/code/session_0197gRFp4QFxu2VzxhTEozGn