[Bug]: WorkflowProfiler reports zero elapsed time on Windows with Python <= 3.12

Aperta
  • Qualcosa non va?
#2,599 1 commento 0 reazioni 0 assegnatari Vedi su GitHub

I maintainer di solito rispondono entro 5 giorni

Nessuno ha ancora preso questa issue.

Valutazione

Difficoltà
2/5
Tempo stimato
1-3 ore
Idoneità per principianti
38/100
Tipo di issue
Bug
Chiarezza
Specificata chiaramente
Stato di attività
Attiva
Stack tecnologico
python
Ambito
performance, testing-qa

Direzione di ricerca

Start with WorkflowProfiler in profiling.py, total_runtime in run_pipeline.py, and tests/unit/indexing/test_profiling.py; check how elapsed time is measured and run the profiling tests on Windows with Python 3.11 or 3.12. Done means short workflows report positive elapsed time and pipeline runtime remains monotonic. The issue author says a fix and regression test are ready and that they plan to open a pull request, so check for work already underway before starting.

Scritto dal modello di indicizzazione a partire dal testo della issue.

Descrizione

Describe the bug

WorkflowProfiler (and the pipeline total_runtime in run_pipeline.py) measure elapsed time with time.time(). On Windows, time.time() has a 15.6 ms resolution with Python <= 3.12 (it uses GetSystemTimeAsFileTime); CPython 3.13 switched to GetSystemTimePreciseAsFileTime with a 1 microsecond resolution (What's New in Python 3.13 - time).

Since pyproject.toml declares requires-python = ">=3.11,<3.14" but the unit-test CI matrix only runs Python 3.13, this bug is invisible to CI and affects every Windows user on Python 3.11/3.12:

  1. context.stats.workflows[name] = profiler.metrics writes overall = 0.0 for any workflow body shorter than one scheduler tick, so stats.json reports 0 ms per workflow on Windows with Python 3.11/3.12.
  2. tests/unit/indexing/test_profiling.py::TestWorkflowProfiler::test_handles_exception_in_context fails deterministically (assert 0.0 > 0), because the test body is microsecond-scale.
  3. time.time() is also a wall clock, so NTP adjustments can make elapsed/total_runtime negative or inflated; time.perf_counter() is the documented clock for measuring elapsed durations.
Steps to reproduce

On Windows with Python 3.11 or 3.12:

uv sync --all-packages
uv run pytest tests/unit/indexing/test_profiling.py

test_handles_exception_in_context fails with assert 0.0 > 0 on both 3.11.15 and 3.12.4 (verified: 11/11 pytest runs across both versions). A 300-iteration measurement of the exact try/with/raise block used by the test reports 298/300 zero elapsed values (99.3%), median 0.0, max 1.0 ms. The same test passes on Python 3.13 (3/3), which is exactly why the CI matrix (Python 3.13 only x ubuntu/windows) stays green while the supported versions fail.

Minimal clock probe on Windows, Python 3.12.4:

import time
zero = sum(
    (lambda t0: ([0] * 1000, time.time() - t0)[1] == 0.0)(time.time())
    for _ in range(200)
)
# -> 200/200 zero samples for a microsecond-scale body
Expected Behavior

WorkflowProfiler.overall and pipeline.total_runtime must be positive and monotonic regardless of Python version or OS. Elapsed-time measurement should use time.perf_counter() (high-resolution monotonic clock), per the Python docs recommendation for benchmarking.

GraphRAG Config Used

Not config-dependent; reproducible with the unit test suite alone.

Logs and screenshots
FAILED tests/unit/indexing/test_profiling.py::TestWorkflowProfiler::test_handles_exception_in_context - assert 0.0 > 0
 +  where 0.0 = WorkflowMetrics(overall=0.0, peak_memory_bytes=8480, memory_delta_bytes=8480, tracemalloc_overhead_bytes=1104).overall
Additional Information
  • GraphRAG Version: main (5faaaf4f5, post-3.3.0)
  • Operating System: Windows 11 (24H2, x64)
  • Python Version: 3.11.15, 3.12.4 (failing), 3.13.x (passing)
  • Related Issues: none found for this failure mode

I have a minimal fix ready (time.perf_counter() in profiling.py + run_pipeline.py, plus a regression test guarding positive elapsed time for sub-tick bodies) and will open a PR referencing this issue.

Lingua principale
Python
Stelle
36.6k
Fork
3.9k
Merge medio
4g 11h
PR unite (30g)
1

Preparare l'ambiente

Come iniziare

  1. Leggi tutta la issue e poi la guida ai contributi del progetto.
  2. Commenta sulla issue per dire che te ne occupi tu — evita che due persone facciano lo stesso lavoro.
  3. Fai un fork del repository e lavora su un branch.
  4. Apri una pull request che faccia riferimento al numero della issue.

Altre issue di microsoft/graphrag

Tutte le issue di microsoft/graphrag

Issue simili

Altre issue su Python

Ricevi le nuove issue nella tua casella

Un breve riepilogo di issue GitHub adatte ai principianti.