Skip to content

UN-2771 [FEAT] Report text extraction time in API deployment metrics#2032

Open
athul-rs wants to merge 4 commits into
mainfrom
UN-2771-extraction-time-metric
Open

UN-2771 [FEAT] Report text extraction time in API deployment metrics#2032
athul-rs wants to merge 4 commits into
mainfrom
UN-2771-extraction-time-metric

Conversation

@athul-rs

@athul-rs athul-rs commented Jun 11, 2026

Copy link
Copy Markdown
Contributor

What

  • API deployment responses with include_metrics=True now report the text extraction (LLMWhisperer/X2Text) duration as metrics._pipeline.extraction["time_taken(s)"], alongside the existing per-output indexing time.
"metrics": { "_pipeline": { "extraction": { "time_taken(s)": 1.23 } } }

The metric lives under a reserved _pipeline namespace rather than a bare top-level extraction key: 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_pipeline times the extract step (time.monotonic()) and _finalize_pipeline_result merges {"extraction": {"time_taken(s)": ...}} into result metrics via the existing _merge_pipeline_metrics, exactly mirroring how _index_pipeline_output records 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)

  • No. Additive metrics key only, under a reserved _pipeline namespace that cannot collide with user-defined output names; existing indexing metrics and response shape unchanged. Paths that skip extraction (smart-table) leave the dict empty — nothing added, same as today.
  • The indexing path was moved from wall-clock datetime.now() to time.monotonic(). Same units and semantics (elapsed seconds as a float), but immune to NTP/system-clock adjustments; it cannot regress a caller.

Database Migrations

  • None

Env Config

  • None

Relevant Docs

  • N/A

Related Issues or PRs

  • Jira: UN-2771

Notes on Testing

  • 5 new unit tests in 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.
  • Worker suite: 723 passed, 6 failed — the same 6 failures present on main (Postgres auth + pre-existing mock assertions), none in the touched paths.
  • ruff check/format clean (pre-commit hooks pass).
  • Manual: run an API deployment (structure-tool workflow routed via the worker pipeline) with 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

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>
@coderabbitai

coderabbitai Bot commented Jun 11, 2026

Copy link
Copy Markdown
Contributor

Walkthrough

The structure pipeline now records extraction duration when extraction runs, uses reserved metric keys, and merges extraction timing with indexing metrics during pipeline finalization. Tests cover successful, skipped, failed, collision, and combined metric scenarios.

Changes

Structure pipeline metrics

Layer / File(s) Summary
Metric contract and pipeline timing flow
workers/executor/executors/constants.py, workers/executor/executors/legacy_executor.py
Adds reserved pipeline metric keys, records extraction and monotonic indexing durations, and merges both metric sets during finalization.
Extraction metrics validation
workers/tests/test_phase5d.py
Verifies extraction timing output, namespace collision handling, coexistence with indexing metrics, skipped extraction, and extraction failure behavior.

Estimated code review effort: 2 (Simple) | ~10 minutes

Suggested reviewers: hari-kuriakose, jaseemjaskp, chandrasekharan-zipstack

🚥 Pre-merge checks | ✅ 5
✅ Passed checks (5 passed)
Check name Status Explanation
Docstring Coverage ✅ Passed Docstring coverage is 100.00% which is sufficient. The required threshold is 80.00%.
Linked Issues check ✅ Passed Check skipped because no linked issues were found for this pull request.
Out of Scope Changes check ✅ Passed Check skipped because no linked issues were found for this pull request.
Title check ✅ Passed The title is clear, concise, and accurately describes the new extraction-time metric in API deployment metrics.
Description check ✅ Passed The description covers the required template sections and is mostly complete; Dependencies Versions is not filled in.
✨ Finishing Touches
📝 Generate docstrings
  • Create stacked PR
  • Commit on current branch
🧪 Generate unit tests (beta)
  • Create PR with unit tests
  • Commit unit tests in branch UN-2771-extraction-time-metric

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.

❤️ Share

Comment @coderabbitai help to get the list of available commands.

@greptile-apps

greptile-apps Bot commented Jun 11, 2026

Copy link
Copy Markdown
Contributor

Greptile Summary

This PR adds extraction timing to API deployment metrics by wrapping the _handle_extract call in _handle_structure_pipeline with time.monotonic() and surfacing the elapsed time as metrics["_pipeline"]["extraction"]["time_taken(s)"]. The _pipeline reserved namespace avoids key collisions with user-defined prompt/output names that share the metrics dict.

  • constants.py: Two new PromptServiceConstants entries (PIPELINE = "_pipeline", TIME_TAKEN = "time_taken(s)") centralise the wire-format keys used by both the new extraction metric and the refactored indexing metric.
  • legacy_executor.py: Extraction timing uses time.monotonic() (consistent with the simultaneous migration of indexing timing away from datetime.datetime.now()); _finalize_pipeline_result first merges index_metrics with extraction_metrics, then merges the combined result into the answer-step metrics via the existing _merge_pipeline_metrics helper.
  • test_phase5d.py: Five new test cases cover the happy path, namespace collision avoidance, index+extraction coexistence, smart-table skip path, and extraction-failure early-return.

Confidence Score: 5/5

Safe to merge — the change is strictly additive, preserving the existing metrics shape and all pre-existing paths.

The extraction timing uses a monotonic clock and is nested under a reserved _pipeline key that cannot collide with user-defined output names. Both index and extraction paths are well-covered by new unit tests. Smart-table and failure early-return paths are explicitly verified to produce no extraction metric. No schema or database changes; existing consumers see only a new sibling key they can safely ignore.

No files require special attention.

Important Files Changed

Filename Overview
workers/executor/executors/constants.py Added PIPELINE="_pipeline" and TIME_TAKEN="time_taken(s)" constants to PromptServiceConstants; clearly annotated as reserved namespaces.
workers/executor/executors/legacy_executor.py Adds monotonic-clock timing around the extraction step, stores result under the reserved _pipeline namespace to avoid collision with user-defined output names, updates _finalize_pipeline_result to merge extraction_metrics alongside index_metrics, and migrates indexing timing from datetime to time.monotonic().
workers/tests/test_phase5d.py Adds TestExtractionMetrics with 5 scenarios covering normal extraction, namespace collision avoidance, index+extraction co-existence, skip-extraction path, and failed-extraction early return.

Sequence Diagram

%%{init: {'theme': 'neutral'}}%%
sequenceDiagram
    participant C as Caller
    participant HS as _handle_structure_pipeline
    participant HE as _handle_extract (X2Text)
    participant FP as _finalize_pipeline_result
    participant MM as _merge_pipeline_metrics

    C->>HS: execute(context)
    alt "skip_extraction == False"
        HS->>HS: "extraction_start = time.monotonic()"
        HS->>HE: _handle_extract(extract_ctx)
        HE-->>HS: ExtractResult(success, data)
        HS->>HS: "extraction_time = time.monotonic() - extraction_start"
        HS->>HS: "extraction_metrics = {_pipeline: {extraction: {time_taken(s): t}}}"
    else "skip_extraction == True (smart-table)"
        HS->>HS: "extraction_metrics = {} (empty)"
    end
    HS->>HS: run index / answer steps
    HS->>FP: finalize(structured_output, index_metrics, extraction_metrics)
    FP->>MM: merge(index_metrics, extraction_metrics)
    MM-->>FP: merged new_metrics
    FP->>MM: merge(existing_metrics, new_metrics)
    MM-->>FP: final metrics dict
    FP-->>HS: structured_output updated
    HS-->>C: "ExecutionResult(success, data=structured_output)"
Loading
%%{init: {'theme': 'base', 'themeVariables': {"darkMode": true, "background": "#0d1117", "primaryColor": "#21262d", "primaryTextColor": "#e6edf3", "primaryBorderColor": "#8b949e", "lineColor": "#8b949e", "textColor": "#e6edf3", "edgeLabelBackground": "#161b22", "actorBkg": "#21262d", "actorBorder": "#8b949e", "actorTextColor": "#e6edf3", "actorLineColor": "#8b949e", "signalColor": "#8b949e", "signalTextColor": "#e6edf3", "noteBkgColor": "#373320", "noteBorderColor": "#d4a72c", "noteTextColor": "#f0e6c0", "labelBoxBkgColor": "#21262d", "labelBoxBorderColor": "#8b949e", "labelTextColor": "#e6edf3", "loopTextColor": "#e6edf3", "activationBkgColor": "#30363d", "activationBorderColor": "#8b949e"}}}%%
sequenceDiagram
    participant C as Caller
    participant HS as _handle_structure_pipeline
    participant HE as _handle_extract (X2Text)
    participant FP as _finalize_pipeline_result
    participant MM as _merge_pipeline_metrics

    C->>HS: execute(context)
    alt "skip_extraction == False"
        HS->>HS: "extraction_start = time.monotonic()"
        HS->>HE: _handle_extract(extract_ctx)
        HE-->>HS: ExtractResult(success, data)
        HS->>HS: "extraction_time = time.monotonic() - extraction_start"
        HS->>HS: "extraction_metrics = {_pipeline: {extraction: {time_taken(s): t}}}"
    else "skip_extraction == True (smart-table)"
        HS->>HS: "extraction_metrics = {} (empty)"
    end
    HS->>HS: run index / answer steps
    HS->>FP: finalize(structured_output, index_metrics, extraction_metrics)
    FP->>MM: merge(index_metrics, extraction_metrics)
    MM-->>FP: merged new_metrics
    FP->>MM: merge(existing_metrics, new_metrics)
    MM-->>FP: final metrics dict
    FP-->>HS: structured_output updated
    HS-->>C: "ExecutionResult(success, data=structured_output)"
Loading

Reviews (4): Last reviewed commit: "UN-2771 Address review: namespace the me..." | Re-trigger Greptile

@chandrasekharan-zipstack chandrasekharan-zipstack left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@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>
@athul-rs

Copy link
Copy Markdown
Contributor Author

@chandrasekharan-zipstack you were right — reworked. The tools/structure change (and the tool version bump) is reverted; extraction timing now lives in the celery flow: LegacyExecutor._handle_structure_pipeline times the extract step and merges extraction.time_taken(s) into result metrics through _finalize_pipeline_result/_merge_pipeline_metrics, mirroring the existing indexing timing in _index_pipeline_output. Confirmed the worker path is what cloud runs (workflows using the structure tool image are routed to it via _is_structure_tool_workflow). PR is now a 12-line change to legacy_executor.py only.

@sonarqubecloud

Copy link
Copy Markdown

@coderabbitai coderabbitai Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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

📥 Commits

Reviewing files that changed from the base of the PR and between ab98fc5 and ec778bc.

📒 Files selected for processing (1)
  • workers/executor/executors/legacy_executor.py

Comment thread workers/executor/executors/legacy_executor.py

@jaseemjaskp jaseemjaskp left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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 a float >= 0 and coexists with per-prompt keys.
  • test_extract_failure_records_no_extraction_metric — metric is computed after the _failure early-return, so a failed extract must record no timing (pin via a _finalize_pipeline_result spy / assert_not_called).
  • test_index_and_extraction_metrics_merged — both families merge (top-level extraction + per-output indexing).
  • test_skip_extraction_records_no_extraction_metricskip_extraction ⇒ no "extraction" key.

Comment thread workers/executor/executors/legacy_executor.py Outdated
Comment thread workers/executor/executors/legacy_executor.py
Comment thread workers/executor/executors/legacy_executor.py Outdated
… 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>
@sonarqubecloud

Copy link
Copy Markdown

@athul-rs

Copy link
Copy Markdown
Contributor Author

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 extraction key. It is nested under a reserved _pipeline namespace, so the response shape is now:

"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 (test_phase5d.py::TestExtractionMetrics):

  • test_extraction_metrics_recorded — normal run, time_taken(s) is a float >= 0.
  • test_extraction_metric_does_not_collide_with_output_name — a prompt named "extraction" and the pipeline metric coexist untouched.
  • test_index_and_extraction_metrics_merged — per-output indexing + top-level _pipeline.extraction both survive the merge.
  • test_skip_extraction_records_no_extraction_metric — smart-table path adds no _pipeline key.
  • test_extract_failure_records_no_extraction_metric — timing is taken after the failure early-return, pinned with a _finalize_pipeline_result spy and assert_not_called.

Also fixed: PSKeys.EXTRACTION / PSKeys.PIPELINE instead of literals; "time_taken(s)" promoted to PSKeys.TIME_TAKEN; and the indexing path moved off wall-clock datetime.now() onto time.monotonic() so both producers use the same (correct) clock — I did this here rather than deferring it, since the PR was what introduced the inconsistency.

Verification: worker suite is 723 passed, 6 failed — the same 6 failures present on main (Postgres auth + pre-existing mock assertions), none in the touched paths. Branch is up to date with main.

@github-actions

Copy link
Copy Markdown
Contributor

Unstract test results

Per-group results

Status Group Tier Passed Failed Errors Skipped Duration (s)
e2e-login e2e 2 0 0 0 1.5
e2e-smoke e2e 2 0 0 0 1.3
integration-backend integration 56 0 0 27 46.0
integration-connectors integration 1 0 0 7 8.1
unit-backend unit 126 0 0 0 21.9
unit-connectors unit 63 0 0 0 9.8
unit-core unit 27 0 0 0 1.3
unit-platform-service unit 15 0 0 0 2.6
unit-rig unit 69 0 0 0 3.6
unit-sdk1 unit 435 0 0 0 24.5
unit-workers unit 0 0 0 0 28.9
TOTAL 796 0 0 34 149.4

Critical paths

⚠️ Critical paths not yet covered

  • workflow-create-execute — Create a workflow, configure source+destination, execute, poll, fetch result. (entry: POST /api/v1/workflow/{id}/execute/; declared coverage: e2e-workflow)
  • api-deployment-run — Deploy a workflow as an API, POST a document, receive structured JSON. (entry: POST /deployment/api/{org}/{name}/; declared coverage: e2e-api-deployment)
  • prompt-studio-fetch-response — Prompt Studio: create project, add prompt, run single-pass, get response. (entry: POST /api/v1/prompt-studio/prompt-studio-tool/{id}/fetch_response/; declared coverage: e2e-prompt-studio)
  • pipeline-etl-execute — Run an ETL pipeline from source connector to destination. (entry: POST /api/v1/pipeline/{id}/execute/; declared coverage: no groups declared)
  • usage-token-tracking — Per-execution token usage is recorded and retrievable. (entry: GET /api/v1/usage/get_token_usage/; declared coverage: no groups declared)
  • workflow-execution-fan-out — Multi-file workflow execution fans out to file-processing workers and rejoins. (entry: internal: backend → rabbitmq → workers/file_processing; declared coverage: no groups declared)
  • callback-result-delivery — Async results are posted back via the callback worker. (entry: internal: workers/callback → backend /internal endpoints; declared coverage: no groups declared)
✅ Covered critical paths
  • auth-login — covered by e2e-login
  • adapter-register-llm — covered by integration-backend

@chandrasekharan-zipstack chandrasekharan-zipstack left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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).

  1. _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 _file is the intuitive/consistent name.
  2. extractiontext_extraction — avoids confusion with extraction_llm (the extraction-purpose LLM call) which sits beside it in the same metrics dict; the collision is visible in single-pass responses (extraction_llm and _pipeline.extraction coexist).

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.

EXTRACTION = "extraction"
# Reserved namespace for pipeline-level metrics so they cannot collide with
# user-defined output/prompt names at the top level of the metrics dict.
PIPELINE = "_pipeline"

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Rename PIPELINE = "_pipeline"FILE = "_file". This bucket holds file-level (whole-document) metrics, and "file" is the existing API response key for the source file (workflow_manager/workflow_v2/dto.py:45) — _file reads intuitively and matches convention.

Also add a sibling constant for the metric name so it doesn't collide with extraction_llm:

TEXT_EXTRACTION = "text_extraction"

Update the comment above to match.

# collides with a user-defined output named "extraction" during
# the top-level metrics merge (see _merge_pipeline_metrics).
extraction_metrics = {
PSKeys.PIPELINE: {

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Use the renamed constants here:

extraction_metrics = {
    PSKeys.FILE: {
        PSKeys.TEXT_EXTRACTION: {PSKeys.TIME_TAKEN: extraction_time}
    }
}

Also update the adjacent # Nest under a reserved "_pipeline"… comment and the _finalize_pipeline_result docstring (the {"_pipeline": {"extraction": …}} shape example) to _file / text_extraction.



class TestExtractionMetrics:
"""Extraction duration is reported under the reserved _pipeline namespace.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Update these tests for the renamed keys: metrics["_pipeline"]["extraction"]metrics["_file"]["text_extraction"], the "_pipeline" not in metrics assertion → "_file", and this docstring's _pipeline namespace wording.

Worth adding one single-pass assertion too: since _file.text_extraction is merged by the shared finalize, a single-pass run should show the same _file bucket alongside its flat context_retrieval / extraction_llm — locks in the cross-mode consistency.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants