perf(diff): tighten diff-scan poll ceiling and make its timing attributable

A finished comparison could sit unobserved for up to 30s between polls, which is
dead time on every PR job. Lower the ceiling to 10s: a multi-minute comparison
costs roughly 2x the polls while cutting worst-case dead time to 10s.

Diff scans now log their ID, poll count, and the wait before the final poll at
INFO. Previously the ID was debug-only, so a slow comparison in a customer CI log
could not be tied back to a server-side diff scan, and there was no way to tell
backend comparison time apart from time the result spent ready-but-unpolled.

Also document the diff-scans token scopes. A token missing them still completes
the scan, silently falling back to the streaming comparison, which differs in both
transport and payload (cached diff-scan responses always embed per-package license
details; the streaming path requests a lean payload).

Ref: CE-379

Author: lelia

CHANGELOG.md

@@ -22,6 +22,17 @@
   smaller local fallback pattern set. Manifest results from `--sub-path` routing
   are reused during scan creation.
 
+### Changed: scan comparison timing is easier to attribute
+
+- Lowered the diff-scan poll ceiling from 30s to 10s. A finished comparison is no
+  longer left unobserved for up to half a minute, which matters when the CLI runs
+  inside a CI step with a per-step time budget.
+- Diff scans now log their ID, poll count, and the wait before the final poll, so
+  a CI log distinguishes backend comparison time from time spent between polls.
+- Documented the `diff-scans:create`, `diff-scans:list` and `full-scans:list`
+  token scopes. Without them the comparison silently falls back to the older
+  streaming path.
+
 ## 2.6.4
 
 ### Changed: bump pinned @coana-tech/cli to 15.10.13

docs/troubleshooting.md

@@ -1,5 +1,34 @@
 # Troubleshooting
 
+## API token scopes for scan comparisons
+
+PR/MR runs compare the new scan against the repository's head scan. That comparison
+first uses the diff-scans endpoints, which require an organization token with these
+scopes in addition to whatever the scan itself needs:
+
+- `diff-scans:create`
+- `diff-scans:list`
+- `full-scans:list`
+
+If the token is missing them the scan still succeeds, so this is easy to miss. The only
+signal is a warning, after which the CLI falls back to the older streaming comparison:
+
+```
+Diff scan comparison failed with APIAccessDenied(Insufficient permissions), falling back to the streaming scan comparison
+```
+
+Grant the scopes to use the diff-scans path. It polls with short, bounded requests
+rather than holding one connection open while the backend computes, which is what lets
+large comparisons survive network idle timeouts — notably Azure NAT gateways, which
+reap idle connections after four minutes and surface as an intermittent
+`ConnectionResetError`.
+
+The two paths can take noticeably different amounts of time on the same repository,
+because cached diff-scan responses always embed per-package license details while the
+streaming comparison requests a lean payload. On a large dependency tree, compare the
+`Diff scan comparison ready in ...` timing against the `Diff Report Gathered in ...`
+total before assuming either path is at fault.
+
 ## Common gotchas
 
 - In diff scope, `--strict-blocking` uses a stricter alert set (`new + unchanged`) for blocking checks and diff-based output selection.

socketsecurity/core/__init__.py

@@ -103,8 +103,15 @@
 # minutes to compute. The timeout is a backstop against a diff scan that never
 # completes; on expiry (or any other failure of this flow) the caller falls back to the
 # legacy streaming comparison rather than failing the scan outright.
+#
+# The max interval is also the upper bound on how long a finished comparison sits
+# unnoticed between polls, which is dead time added to every PR job. Callers commonly
+# run this inside a CI step with a per-step time budget of a few minutes, so the cap is
+# kept small: a multi-minute comparison costs roughly 2x the polls of a 30s cap while
+# cutting the worst-case dead time from 30s to 10s. Diff scans log their poll count and
+# last interval on completion so this tradeoff can be re-evaluated against real timings.
 DIFF_SCAN_POLL_INITIAL_INTERVAL_SECONDS = 5.0
-DIFF_SCAN_POLL_MAX_INTERVAL_SECONDS = 30.0
+DIFF_SCAN_POLL_MAX_INTERVAL_SECONDS = 10.0
 DIFF_SCAN_POLL_BACKOFF_MULTIPLIER = 1.5
 DIFF_SCAN_POLL_TIMEOUT_SECONDS = 30 * 60.0
 
@@ -1584,6 +1591,10 @@ def get_diff_scan_artifacts(
                 "Error creating or resolving diff scan: "
                 f"unexpected response: {str(response_summary)[:500]}"
             )
+        # Logged at INFO, not debug: this is the only identifier that ties a slow or
+        # failed comparison in a CI log back to a server-side diff scan, and it is
+        # needed even when the run later falls back to the streaming comparison.
+        log.info(f"Diff scan created: id={diff_scan_id}")
         artifacts_dict = diff_scan.get("artifacts")
 
         # cached=true is the polling contract (202 while computing, 200 when
@@ -1595,8 +1606,14 @@ def get_diff_scan_artifacts(
         # response.json() fails and the caller falls back to the legacy
         # streaming comparison, which still requests the lean payload.
         poll_params = {"cached": "true"}
-        deadline = time.monotonic() + DIFF_SCAN_POLL_TIMEOUT_SECONDS
+        poll_start = time.monotonic()
+        deadline = poll_start + DIFF_SCAN_POLL_TIMEOUT_SECONDS
         interval = DIFF_SCAN_POLL_INITIAL_INTERVAL_SECONDS
+        # Tracked so the completion log can separate backend compute time from time the
+        # result spent ready-but-unpolled: the wait before the final poll bounds the
+        # latter, which is otherwise invisible in a CI log.
+        polls = 0
+        last_interval = 0.0
         while artifacts_dict is None:
             try:
                 response = self.sdk.diffscans.get(self.config.org_slug, diff_scan_id, params=poll_params)
@@ -1610,13 +1627,19 @@ def get_diff_scan_artifacts(
                     f"({type(error).__name__}), retrying in {interval:.0f}s"
                 )
                 response = {"status": "processing"}
+            polls += 1
             if response.get("status") != "processing":
                 scan = response.get("diff_scan") or {}
                 if scan.get("artifacts") is None:
                     raise Exception(
                         f"Error fetching diff scan {diff_scan_id}: unexpected response: {str(response)[:500]}"
                     )
                 artifacts_dict = scan["artifacts"]
+                log.info(
+                    "Diff scan comparison ready in "
+                    f"{time.monotonic() - poll_start:.2f}s: id={diff_scan_id}, "
+                    f"polls={polls}, wait_before_final_poll={last_interval:.0f}s"
+                )
                 break
             if time.monotonic() >= deadline:
                 raise Exception(
@@ -1625,6 +1648,7 @@ def get_diff_scan_artifacts(
                 )
             log.debug(f"Diff scan {diff_scan_id} still processing, polling again in {interval:.0f}s")
             time.sleep(interval)
+            last_interval = interval
             interval = min(interval * DIFF_SCAN_POLL_BACKOFF_MULTIPLIER, DIFF_SCAN_POLL_MAX_INTERVAL_SECONDS)
 
         return DiffArtifacts.from_dict({

tests/core/test_diff_scan_polling.py

@@ -120,3 +120,36 @@ def test_fallback_to_streaming_diff_on_failure(core):
     )
     assert "dp3" in added
     assert "dp2" in removed
+
+
+def test_completion_log_reports_id_polls_and_final_wait(
+        core, diff_scan_get_response, no_sleep, caplog, monkeypatch
+):
+    """The completion log must let a CI log separate backend compute time from the
+    time a finished comparison sat unnoticed between polls."""
+    import logging
+
+    monkeypatch.setattr(core_module, "DIFF_SCAN_POLL_INITIAL_INTERVAL_SECONDS", 4.0)
+    monkeypatch.setattr(core_module, "DIFF_SCAN_POLL_MAX_INTERVAL_SECONDS", 6.0)
+    processing = {"status": "processing", "id": "diff-scan-123"}
+    core.sdk.diffscans.get.side_effect = [processing, processing, diff_scan_get_response]
+
+    with caplog.at_level(logging.INFO, logger="socketdev"):
+        core.get_diff_scan_artifacts("head", "new")
+
+    messages = [record.message for record in caplog.records]
+    assert any("Diff scan created: id=" in message for message in messages)
+    ready = next(message for message in messages if "Diff scan comparison ready" in message)
+    assert "polls=3" in ready
+    # Waits were 4s then 6s (capped); the final poll followed the 6s wait, which is
+    # the upper bound on how long the result was ready before being observed.
+    assert "wait_before_final_poll=6s" in ready
+
+
+def test_max_poll_interval_bounds_dead_time_for_ci_budgets():
+    """A finished comparison is never left unobserved longer than the max interval."""
+    assert core_module.DIFF_SCAN_POLL_MAX_INTERVAL_SECONDS <= 10.0
+    assert (
+        core_module.DIFF_SCAN_POLL_INITIAL_INTERVAL_SECONDS
+        <= core_module.DIFF_SCAN_POLL_MAX_INTERVAL_SECONDS
+    )