gpt-5.3 codex review: Phase 4

tests/services/test_workflows_reliability.py

@@ -181,6 +181,74 @@ class TestWorkflowReliability:
         assert duration_ms >= int(budget_seconds * 1000 * 0.9)
         assert duration_ms < int((budget_seconds + setup_seconds) * 1000 * 0.9)
 
+    @pytest.mark.asyncio
+    async def test_attempt_metadata_persists_provider_and_processing_durations(
+        self,
+        default_session_factory,
+        monkeypatch,
+    ):
+        """Execution metadata records both provider-only and end-to-end durations."""
+        services = ServiceBundle.from_session_factory(default_session_factory)
+        async with services.jobs._session_scope() as session:
+            document = Document(id=uuid4(), name="timing-metadata-doc")
+            session.add(document)
+            await session.flush()
+            job = Job(document_id=document.id, status=JobStatus.QUEUED)
+            session.add(job)
+            await session.flush()
+            source = Source(
+                document_id=document.id,
+                page_number=1,
+                upload_name="timing.jpg",
+                filename="timing.jpg",
+                file_path=str(Path("tests/fixtures/images/real/Book Two - page 02.jpg")),
+                file_hash="f" * 64,
+                file_size_bytes=1,
+            )
+            session.add(source)
+            await session.flush()
+            session.add(JobSource(job_id=job.id, source_id=source.id, status=JobSourceStatus.PENDING))
+            await session.commit()
+            loaded = await services.jobs.read_job(job_id=job.id, session=session)
+
+        async def _returns_text(*args, **kwargs):
+            _ = (args, kwargs)
+            await asyncio.sleep(0.03)
+            return TranscriptionResult(text="timed output", provider="fixture", model="fixture-model")
+
+        monkeypatch.setattr("transcription.services.workflows.transcribe_document_image", _returns_text)
+
+        result = await process_queued_job(
+            job=loaded,
+            services=services,
+            settings=Settings(openrouter_api_key="test-key", worker_provider_timeout_seconds=2.0),
+        )
+        assert result is not None
+        assert result.status == JobStatus.TRANSCRIBED
+
+        async with services.jobs._session_scope() as session:
+            attempts = (
+                (
+                    await session.exec(
+                        select(ExecutionAttempt).where(
+                            col(ExecutionAttempt.job_source_id).in_([js.id for js in result.job_sources])
+                        )
+                    )
+                )
+                .all()
+            )
+        assert len(attempts) == 1
+        attempt = attempts[0]
+        timing = (attempt.normalized_metadata or {}).get("processing_timing")
+        assert isinstance(timing, dict)
+        provider_call_ms = timing.get("provider_call_duration_ms")
+        processing_ms = timing.get("processing_duration_ms")
+        assert isinstance(provider_call_ms, int)
+        assert isinstance(processing_ms, int)
+        assert provider_call_ms >= 0
+        assert processing_ms >= provider_call_ms
+        assert attempt.duration_ms == provider_call_ms
+
     @pytest.mark.asyncio
     async def test_error_after_claim_fails_the_job_instead_of_stranding_it(
         self,
@@ -239,7 +307,7 @@ class TestWorkflowReliability:
             assert final.status == JobStatus.FAILED
 
     @pytest.mark.asyncio
-    async def test_completed_page_is_committed_before_next_provider_call_finishes(
+    async def test_transcribed_page_is_committed_before_next_provider_call_finishes(
         self,
         default_session_factory,
         monkeypatch,