UN-2771 [FEAT] Report text extraction time in API deployment metrics - #2032
Conversation
The structure tool timed indexing but not the text extraction (LLMWhisperer/X2Text) call, so API responses with include_metrics=True reported indexing time only. Time dynamic_extraction the same way and merge it into the result metrics as extraction.time_taken(s). Bump structure tool to 0.0.102. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
|
Note Reviews pausedIt looks like this branch is under active development. To avoid overwhelming you with review comments due to an influx of new commits, CodeRabbit has automatically paused this review. You can configure this behavior by changing the Use the following commands to manage reviews:
Use the checkboxes below for quick actions:
No actionable comments were generated in the recent review. 🎉 ℹ️ Recent review info⚙️ Run configurationConfiguration used: Organization UI Review profile: CHILL Plan: Pro Run ID: 📒 Files selected for processing (3)
🚧 Files skipped from review as they are similar to previous changes (1)
Summary by CodeRabbit
WalkthroughThe structure pipeline now reports extraction and indexing durations using shared metric keys. Extraction timing is stored under a reserved file-level namespace, merged with indexing metrics, and covered by tests for success, skipping, failure, single-pass execution, and metric-name collisions. ChangesPipeline timing metrics
Estimated code review effort: 3 (Moderate) | ~20 minutes Sequence Diagram(s)sequenceDiagram
participant StructurePipeline
participant Extract
participant IndexPipelineOutput
participant FinalizePipelineResult
StructurePipeline->>Extract: execute extraction
Extract-->>StructurePipeline: return extracted output
StructurePipeline->>IndexPipelineOutput: index pipeline output
IndexPipelineOutput-->>StructurePipeline: return indexing metrics
StructurePipeline->>FinalizePipelineResult: pass extraction and indexing metrics
FinalizePipelineResult-->>StructurePipeline: write merged metrics
Suggested reviewers: 🚥 Pre-merge checks | ✅ 5✅ Passed checks (5 passed)
✨ Finishing Touches📝 Generate docstrings
🧪 Generate unit tests (beta)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
|
| Filename | Overview |
|---|---|
| workers/executor/executors/constants.py | Adds FILE = "_file", TEXT_EXTRACTION = "text_extraction", and TIME_TAKEN = "time_taken(s)" constants to PromptServiceConstants. Clean addition; constants are consistent with their usage throughout the PR. |
| workers/executor/executors/legacy_executor.py | Adds time.monotonic() extraction timing in _handle_structure_pipeline, passes extraction_metrics to _finalize_pipeline_result, and migrates indexing timer from datetime.datetime.now() to time.monotonic(). Logic is correct; extraction_metrics is always initialized before the try-block so it is always defined at call-site. |
| workers/file_processing/structure_tool_task.py | Adds _agentic_extraction_seconds and _merge_agentic_metrics helpers to fold agentic executor X2Text durations into the file-level _file.text_extraction bucket and per-prompt table_extraction entries. De-collision for _file-named prompts is correct; the summing logic for multi-prompt agentic runs is sound. |
| workers/tests/test_structure_pipeline.py | Adds TestExtractionMetrics with 6 tests covering the happy path, collision avoidance, index+extraction merge, skip-extraction guard, single-pass, and extract-failure. Tests assert against metrics["_file"]["text_extraction"]["time_taken(s)"], consistent with the implementation. |
| workers/tests/test_agentic_operations.py | Adds TestAgenticExtractionMetrics with 8 tests: summing across prompts, malformed/missing timing, all-agentic run, mixed run accumulation, per-prompt placement, no-agentic guard, zero-duration omission, and the _file (prompt) de-collision key. Coverage is thorough and tests are well-reasoned. |
Flowchart
%%{init: {'theme': 'neutral'}}%%
flowchart TD
A[execute_structure_tool_impl] --> B{agentic_table_outputs?}
B -- yes --> C[Run agentic executor per prompt]
C --> D[Collect agentic_metrics per prompt]
B -- no/also --> E{regular_outputs?}
D --> E
E -- yes --> F[LegacyExecutor._handle_structure_pipeline]
F --> G{skip_extraction?}
G -- no --> H[_handle_extract + time.monotonic]
H --> I[extraction_metrics = _file.text_extraction.time_taken_s]
G -- yes --> J[extraction_metrics = empty dict]
I --> K[_finalize_pipeline_result]
J --> K
K --> L[_merge_pipeline_metrics index_metrics + extraction_metrics]
L --> M[_merge_pipeline_metrics existing_metrics + new_metrics]
M --> N[structured_output.metrics]
E -- no/all-agentic --> O[structured_output = agentic_only dict]
N --> P[_merge_agentic_metrics]
O --> P
D --> P
P --> Q{prompt named _file?}
Q -- yes --> R[rename to _file prompt + warn]
Q -- no --> S[metrics.prompt_name.table_extraction = prompt_metrics]
R --> S
S --> T[Sum extraction seconds across prompts]
T --> U{seconds > 0?}
U -- yes --> V[metrics._file.text_extraction.time_taken_s += seconds]
U -- no --> W[leave _file bucket absent]
V --> X[Final metrics dict]
W --> X
Reviews (10): Last reviewed commit: "UN-2771 Rehome a prompt named _file inst..." | Re-trigger Greptile
chandrasekharan-zipstack
left a comment
chandrasekharan-zipstack
left a comment
There was a problem hiding this comment.
@athul-rs I like your intent here however I don't think the tool related code or logic is being used anymore. This is deprecated and in fact we'll be removing this code soon. Can you check if this is handled in the equivalent flow involving the celery tasks and ensure this concern is addressed?
cc: @harini-venkataraman
Per review, the structure tool's Docker path is deprecated — the live
flow is the celery-based LegacyExecutor structure pipeline. Time the
extract step there and merge {'extraction': {'time_taken(s)': ...}}
into the result metrics alongside the existing per-output indexing
timing. Structure tool changes reverted (no tool version bump needed).
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
|
@chandrasekharan-zipstack you were right — reworked. The |
|
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
There was a problem hiding this comment.
Actionable comments posted: 1
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Inline comments:
In `@workers/executor/executors/legacy_executor.py`:
- Around line 645-647: The current extraction_metrics dict uses a top-level key
"extraction" which can collide with user-defined output/prompt names when merged
later; update this to use a reserved pipeline namespace (e.g., set
extraction_metrics = {"_pipeline": {"extraction": {"time_taken(s)": ...}}}) and
then merge into the main metrics map so pipeline-level metrics live under
metrics["_pipeline"]; adjust the merge logic where metrics and
extraction_metrics are combined (the existing merge around the metrics variable
at lines ~804-811) to preserve the "_pipeline" namespace, or alternatively add a
pre-merge check to disallow user outputs named "extraction" if you prefer the
blocking approach. Ensure you update references to extraction_metrics and the
merge operation accordingly.
🪄 Autofix (Beta)
Fix all unresolved CodeRabbit comments on this PR:
- Push a commit to this branch (recommended)
- Create a new PR with the fixes
ℹ️ Review info
⚙️ Run configuration
Configuration used: Organization UI
Review profile: CHILL
Plan: Pro
Run ID: d5ab6512-472a-43ec-a802-245f014d585e
📒 Files selected for processing (1)
workers/executor/executors/legacy_executor.py
jaseemjaskp
left a comment
jaseemjaskp
left a comment
There was a problem hiding this comment.
Automated review (PR Review Toolkit) of the extraction-time metric.
Net assessment: the merge logic is correct, empty-dict-safe, and introduces no silent failures — error propagation (LegacyExecutorError re-raise) is byte-for-byte unchanged. No blocking bugs. The substantive open item is the top-level-key collision already flagged by @coderabbitai on L647; the inline notes below are distinct consistency/maintainability/test points.
Biggest gap — test coverage (not inline-able; test_phase5d.py isn't in this diff): the PR adds zero tests for the new behavior. _finalize_pipeline_result / _merge_pipeline_metrics are exercised by test_phase5d.py (test_index_metrics_merged L261, test_merge_* L915-927) but none assert on extraction_metrics. Recommend adding before merge:
test_extraction_metrics_recorded— normal run:result.data["metrics"]["extraction"]["time_taken(s)"]is afloat >= 0and coexists with per-prompt keys.test_extract_failure_records_no_extraction_metric— metric is computed after the_failureearly-return, so a failed extract must record no timing (pin via a_finalize_pipeline_resultspy /assert_not_called).test_index_and_extraction_metrics_merged— both families merge (top-levelextraction+ per-outputindexing).test_skip_extraction_records_no_extraction_metric—skip_extraction⇒ no"extraction"key.
… align clocks - Nest extraction timing under a reserved "_pipeline" namespace (PSKeys.PIPELINE) so it cannot collide with a user-defined output/prompt named "extraction" at the top level of the metrics dict. - Use PSKeys.EXTRACTION instead of the hardcoded literal, and capture the duration in a named local for parity with the indexing path. - Promote the duplicated "time_taken(s)" literal to PSKeys.TIME_TAKEN. - Align the indexing path onto time.monotonic(): it measured a duration with wall-clock datetime.now(), which is wrong across NTP/system-clock adjustments and left the two producers of time_taken(s) on different clocks. Drops the now-unused local datetime import. - Document the extraction_metrics shape on _finalize_pipeline_result and type it dict[str, dict] | None. Tests: 5 new cases in test_phase5d.py — metric recorded, name-collision guard, index+extraction merge, skip-extraction, and extract-failure (no timing recorded). Worker suite: 723 passed, same 6 pre-existing failures as main. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
|
Thanks @jaseemjaskp — all four inline threads plus the test-coverage gap are addressed in 81d01ed. Summary of what changed: Design (the substantive one): the metric is no longer a bare top-level "metrics": { "_pipeline": { "extraction": { "time_taken(s)": 1.23 } } }Sibling keys in that dict are user-defined output/prompt names, so the old shape would have collided with a prompt named "extraction". PR description updated to match. Tests — all four you listed, plus one for the collision (
Also fixed: Verification: worker suite is |
chandrasekharan-zipstack
left a comment
chandrasekharan-zipstack
left a comment
There was a problem hiding this comment.
Agreed follow-ups from a design discussion on the metric shape. Two mechanical renames for clarity; plus a heads-up: I filed UN-3714 for the per-profile X2Text extractor being collapsed to the default profile's extractor in the worker pipeline (out of scope for this PR).
_pipeline→_file— the bucket holds file-level (whole-document) metrics, and"file"is already the API response key for the source file (workflow_manager/workflow_v2/dto.py:45), so_fileis the intuitive/consistent name.extraction→text_extraction— avoids confusion withextraction_llm(the extraction-purpose LLM call) which sits beside it in the same metrics dict; the collision is visible in single-pass responses (extraction_llmand_pipeline.extractioncoexist).
Single-pass needs no special-casing: _file.text_extraction is merged in by the shared _finalize_pipeline_result, so single-pass metrics stay flat and just gain the _file sibling — same convention as multi-prompt.
Review follow-up: the reserved bucket holds file-level (whole-document) metrics, so _file matches the existing file key of the API response better than _pipeline. The metric itself becomes text_extraction to stay distinct from extraction_llm, the extraction-purpose LLM call that sits beside it in the same metrics dict. Adds a single-pass test pinning cross-mode consistency: single pass skips indexing but shares _finalize_pipeline_result, so its flat metrics simply gain the same _file sibling the multi-prompt path produces. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
![greptile-apps[bot]](https://avatars.githubusercontent.com/in/867647?s=60&v=4){kind=small}
The extraction timer added by this PR runs only in LegacyExecutor._handle_structure_pipeline. Agentic-table prompts are dispatched to their own executor, which performs its own X2Text, so agentic-only deployments reported no extraction time at all and mixed deployments reported only the legacy pipeline's share. The agentic dispatch was already discarding the executor's result beyond `output.tables`. Read its metrics instead — same `data["metadata"]["metrics"]` shape LegacyExecutor._run_table_extraction uses for the non-agentic table plugin — and fold them in: - per-prompt metrics land beside the legacy pipeline's, under `table_extraction`, so both table routes read alike downstream - any reported X2Text duration is added to `_file.text_extraction`, so the file-level figure covers every extractor that ran The all-agentic branch previously built its result with no `metrics` key at all; it now populates one on the same path. Durations sum rather than replace: each agentic prompt extracts the document itself, so the metric is time spent extracting, not the wall-clock span. An executor reporting no timing leaves the bucket absent rather than writing a misleading zero. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VdHng2GqQpAxBbQs8Ks5Ej
_file is reserved for whole-document metrics, which is why the extraction timing is nested there rather than sitting at the top level beside user-defined output names. The agentic merge wrote per-prompt metrics keyed by prompt name into that same dict, so an agentic_table prompt actually named _file would land its table_extraction metrics inside the reserved bucket, and the extraction total would then write into the same object — conflating the two namespaces the bucket exists to keep apart. Skip the per-prompt entry for that name and log it. The prompt's extraction duration still counts toward the file-level total; only the per-prompt entry is dropped, since there is nowhere collision-free to put it. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VdHng2GqQpAxBbQs8Ks5Ej
Skipping the entry kept the reserved bucket clean but silently lost every other count the prompt reported. Merging it in loses the separation the reserved bucket exists for. Neither is acceptable, so the prompt moves aside instead: its metrics are reported under "_file (prompt)". The reserved key contains no space, so the two can never alias, and nothing the executor reported is discarded. The prompt's extraction duration still counts toward the file-level total as before. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VdHng2GqQpAxBbQs8Ks5Ej
|
Unstract test resultsPer-group results
Critical paths
|
4 participants
What
include_metrics=Truenow report the text extraction (LLMWhisperer/X2Text) duration asmetrics._pipeline.extraction["time_taken(s)"], alongside the existing per-output indexing time.The metric lives under a reserved
_pipelinenamespace rather than a bare top-levelextractionkey: sibling keys in the metrics dict are user-defined output/prompt names, so a prompt named "extraction" would otherwise collide with it.Why
UN-2771 — metrics only included indexing time; the LLMWhisperer call (often the dominant cost for large documents) was invisible, making it hard to attribute slow executions.
How
Reworked per review (@chandrasekharan-zipstack): the original version added timing to
tools/structure(deprecated Docker path); that's reverted. The change now lives in the live celery flow:LegacyExecutor._handle_structure_pipelinetimes the extract step (time.monotonic()) and_finalize_pipeline_resultmerges{"extraction": {"time_taken(s)": ...}}into result metrics via the existing_merge_pipeline_metrics, exactly mirroring how_index_pipeline_outputrecords indexing time. The Prompt Studio IDE flow (_handle_ide_index) is untouched.Can this PR break any existing features. If yes, please list possible items. If no, please explain why. (PS: Admins do not merge the PR without this section filled)
_pipelinenamespace that cannot collide with user-defined output names; existingindexingmetrics and response shape unchanged. Paths that skip extraction (smart-table) leave the dict empty — nothing added, same as today.datetime.now()totime.monotonic(). Same units and semantics (elapsed seconds as a float), but immune to NTP/system-clock adjustments; it cannot regress a caller.Database Migrations
Env Config
Relevant Docs
Related Issues or PRs
Notes on Testing
workers/tests/test_phase5d.py::TestExtractionMetrics: metric recorded, name-collision guard (a prompt named "extraction"), index+extraction merge, skip-extraction records nothing, extract-failure records nothing.723 passed, 6 failed— the same 6 failures present onmain(Postgres auth + pre-existing mock assertions), none in the touched paths.include_metrics=True→ response metrics contain_pipeline.extraction.time_taken(s); smart-table path unchanged.Screenshots
N/A
Checklist
I have read and understood the Contribution Guidelines.
🤖 Generated with Claude Code