Skip to content

Commit 1beace0

Browse files
feat(lexical-graph): emit periodic INFO extraction progress in non-TTY environments (#309)
In non-TTY environments (ECS Fargate -> CloudWatch, Docker, CI), extraction had near-zero progress visibility. LlamaIndex `run_jobs(show_progress=True)` renders a tqdm bar to stderr using carriage returns (\r); line-based log collectors drop or collapse those updates, so operators see no progress. Add a `run_jobs_with_progress` helper (new `indexing/extract/progress.py`) that wraps `run_jobs`: - Interactive TTY: delegates to `run_jobs` unchanged, preserving the live tqdm bar (the caller-supplied `show_progress` is honoured verbatim). - Non-TTY (sys.stderr.isatty() is False): forces `show_progress=False` so the carriage-return tqdm bar is suppressed, and instead emits periodic newline-delimited INFO records ("<desc>: <completed>/<total> (<pct>%)") on a percent/time cadence as jobs complete, with a guaranteed final 100% line. These survive line-based log collection. Wires the helper into the three identical `run_jobs(...)` call sites: proposition_extractor, llm_proposition_extractor, topic_extractor. No new dependencies (stdlib + existing `run_jobs` only). TTY behaviour is unchanged. The repo logging config already defaults to INFO. Fixes #129
1 parent d3aafbd commit 1beace0

5 files changed

Lines changed: 365 additions & 18 deletions

File tree

lexical-graph/src/graphrag_toolkit/lexical_graph/indexing/extract/llm_proposition_extractor.py

Lines changed: 8 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -10,13 +10,13 @@
1010
from graphrag_toolkit.lexical_graph.indexing.model import Propositions
1111
from graphrag_toolkit.lexical_graph.indexing.constants import PROPOSITIONS_KEY
1212
from graphrag_toolkit.lexical_graph.indexing.prompts import EXTRACT_PROPOSITIONS_PROMPT
13+
from graphrag_toolkit.lexical_graph.indexing.extract.progress import run_jobs_with_progress
1314
from graphrag_toolkit.lexical_graph.utils.arg_utils import coalesce
1415

1516
from llama_index.core.schema import BaseNode
1617
from llama_index.core.bridge.pydantic import Field
1718
from llama_index.core.extractors.interface import BaseExtractor
1819
from llama_index.core.prompts import PromptTemplate
19-
from llama_index.core.async_utils import run_jobs
2020
from llama_index.core.schema import NodeRelationship
2121

2222

@@ -130,11 +130,13 @@ async def _extract_propositions_for_nodes(self, nodes):
130130
jobs = [
131131
self._extract_propositions_for_node(node) for node in nodes
132132
]
133-
return await run_jobs(
134-
jobs,
135-
show_progress=self.show_progress,
136-
workers=self.num_workers,
137-
desc=f'Extracting propositions [nodes: {len(jobs)}, num_workers: {self.num_workers}]'
133+
return await run_jobs_with_progress(
134+
jobs,
135+
show_progress=self.show_progress,
136+
workers=self.num_workers,
137+
desc=f'Extracting propositions [nodes: {len(jobs)}, num_workers: {self.num_workers}]',
138+
total=len(jobs),
139+
logger=logger
138140
)
139141

140142
async def _extract_propositions_for_node(self, node):
Lines changed: 149 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,149 @@
1+
# Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved.
2+
# SPDX-License-Identifier: Apache-2.0
3+
4+
"""Progress reporting for asynchronous extraction jobs.
5+
6+
LlamaIndex's ``run_jobs(show_progress=True, ...)`` renders a ``tqdm`` progress
7+
bar to stderr using carriage returns (``\\r``). In interactive terminals this is
8+
a nice live bar, but in non-TTY environments (ECS Fargate -> CloudWatch, Docker,
9+
CI) line-based log collectors drop or collapse the carriage-return updates, so
10+
extraction has near-zero progress visibility (issue #129).
11+
12+
``run_jobs_with_progress`` is a drop-in wrapper around ``run_jobs`` that:
13+
14+
* In an interactive TTY, delegates to ``run_jobs`` unchanged, preserving the
15+
live ``tqdm`` bar.
16+
* In a non-TTY environment, suppresses the ``tqdm`` bar (``show_progress=False``)
17+
and instead emits periodic newline-delimited ``INFO`` log records as jobs
18+
complete, on a percent/time cadence. These survive line-based log collection.
19+
20+
No new dependencies are introduced; only the standard library and the existing
21+
``run_jobs`` import are used.
22+
"""
23+
24+
import logging
25+
import sys
26+
import time
27+
from typing import Any, Coroutine, List, Optional, TypeVar
28+
29+
from llama_index.core.async_utils import run_jobs
30+
31+
logger = logging.getLogger(__name__)
32+
33+
T = TypeVar("T")
34+
35+
# Defaults chosen to be quiet enough for large runs but responsive enough to
36+
# show liveness: log at most every ~10% of progress and no more often than
37+
# every 5 seconds. The final 100% line is always emitted.
38+
DEFAULT_LOG_EVERY_PCT = 10.0
39+
DEFAULT_MIN_INTERVAL_SECONDS = 5.0
40+
41+
42+
def _stderr_is_tty() -> bool:
43+
"""Return whether stderr is an interactive terminal.
44+
45+
Defensive against environments where ``sys.stderr`` is replaced with an
46+
object lacking ``isatty`` (treated as non-TTY).
47+
"""
48+
isatty = getattr(sys.stderr, "isatty", None)
49+
if not callable(isatty):
50+
return False
51+
try:
52+
return bool(isatty())
53+
except Exception: # pragma: no cover - extremely defensive
54+
return False
55+
56+
57+
async def run_jobs_with_progress(
58+
jobs: List[Coroutine[Any, Any, T]],
59+
*,
60+
show_progress: bool = False,
61+
workers: int = 4,
62+
desc: Optional[str] = None,
63+
total: Optional[int] = None,
64+
logger: logging.Logger = logger,
65+
log_every_pct: float = DEFAULT_LOG_EVERY_PCT,
66+
min_interval_seconds: float = DEFAULT_MIN_INTERVAL_SECONDS,
67+
) -> List[T]:
68+
"""Run ``jobs`` concurrently with progress visibility in any environment.
69+
70+
In an interactive TTY this delegates to :func:`run_jobs` with the supplied
71+
``show_progress`` (preserving the live ``tqdm`` bar). In a non-TTY
72+
environment the ``tqdm`` bar is suppressed and periodic newline-delimited
73+
``INFO`` progress records are emitted instead.
74+
75+
Args:
76+
jobs: Coroutines to run, mirroring :func:`run_jobs`.
77+
show_progress: Whether the caller requested a progress bar. Honoured
78+
verbatim in a TTY; forced to ``False`` for ``run_jobs`` in a
79+
non-TTY (periodic INFO logging replaces the bar).
80+
workers: Maximum concurrent jobs, passed through to :func:`run_jobs`.
81+
desc: Human-readable description, used as the log-line prefix and passed
82+
through to :func:`run_jobs` for the ``tqdm`` bar.
83+
total: Total number of jobs (defaults to ``len(jobs)``); used to compute
84+
percentages.
85+
logger: Logger used for periodic INFO progress records.
86+
log_every_pct: Emit a progress record whenever completion advances at
87+
least this many percentage points since the last record. ``0`` logs
88+
on every completed job.
89+
min_interval_seconds: Suppress progress records emitted within this many
90+
seconds of the previous one (the final 100% line is always emitted).
91+
92+
Returns:
93+
Results in the same order as ``jobs`` (matching :func:`run_jobs`).
94+
"""
95+
if total is None:
96+
total = len(jobs)
97+
98+
# Interactive terminal: keep the prior behaviour (live tqdm bar) untouched.
99+
if _stderr_is_tty():
100+
return await run_jobs(
101+
jobs,
102+
show_progress=show_progress,
103+
workers=workers,
104+
desc=desc,
105+
)
106+
107+
# Non-TTY: suppress the carriage-return tqdm bar and emit newline-delimited
108+
# INFO progress on a percent/time cadence instead. We still delegate the
109+
# actual concurrency to run_jobs (with show_progress=False) so its worker
110+
# semantics and result ordering are preserved; each job is wrapped to record
111+
# its completion and emit progress.
112+
prefix = desc if desc else "Progress"
113+
114+
if total <= 0:
115+
# Nothing to do; still delegate so the empty-input contract matches.
116+
return await run_jobs(jobs, show_progress=False, workers=workers, desc=desc)
117+
118+
completed = 0
119+
last_logged_pct = -1.0
120+
last_log_time = 0.0
121+
122+
def _emit(force: bool = False) -> None:
123+
nonlocal last_logged_pct, last_log_time
124+
pct = (completed / total) * 100.0
125+
now = time.monotonic()
126+
if not force:
127+
if (pct - last_logged_pct) < log_every_pct:
128+
return
129+
if (now - last_log_time) < min_interval_seconds:
130+
return
131+
logger.info("%s: %d/%d (%.0f%%)", prefix, completed, total, pct)
132+
last_logged_pct = pct
133+
last_log_time = now
134+
135+
async def _tracked(job: Coroutine[Any, Any, T]) -> T:
136+
nonlocal completed
137+
result = await job
138+
completed += 1
139+
# Always emit the final completion line; otherwise honour the cadence.
140+
_emit(force=(completed == total))
141+
return result
142+
143+
wrapped_jobs = [_tracked(job) for job in jobs]
144+
return await run_jobs(
145+
wrapped_jobs,
146+
show_progress=False,
147+
workers=workers,
148+
desc=desc,
149+
)

lexical-graph/src/graphrag_toolkit/lexical_graph/indexing/extract/proposition_extractor.py

Lines changed: 9 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -9,10 +9,11 @@
99
from graphrag_toolkit.lexical_graph.indexing.model import Propositions
1010
from graphrag_toolkit.lexical_graph.indexing.constants import PROPOSITIONS_KEY
1111

12+
from graphrag_toolkit.lexical_graph.indexing.extract.progress import run_jobs_with_progress
13+
1214
from llama_index.core.schema import BaseNode
1315
from llama_index.core.bridge.pydantic import Field, PrivateAttr
1416
from llama_index.core.extractors.interface import BaseExtractor
15-
from llama_index.core.async_utils import run_jobs
1617

1718
DEFAULT_PROPOSITION_MODEL = 'chentong00/propositionizer-wiki-flan-t5-large'
1819

@@ -160,11 +161,13 @@ async def _extract_propositions_for_nodes(self, nodes):
160161
jobs = [
161162
self._extract_propositions_for_node(node) for node in nodes
162163
]
163-
return await run_jobs(
164-
jobs,
165-
show_progress=self.show_progress,
166-
workers=self.num_workers,
167-
desc=f'Extracting propositions [nodes: {len(nodes)}, num_workers: {self.num_workers}]'
164+
return await run_jobs_with_progress(
165+
jobs,
166+
show_progress=self.show_progress,
167+
workers=self.num_workers,
168+
desc=f'Extracting propositions [nodes: {len(nodes)}, num_workers: {self.num_workers}]',
169+
total=len(nodes),
170+
logger=logger
168171
)
169172

170173
async def _extract_propositions_for_node(self, node):

lexical-graph/src/graphrag_toolkit/lexical_graph/indexing/extract/topic_extractor.py

Lines changed: 8 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -12,13 +12,13 @@
1212
from graphrag_toolkit.lexical_graph.indexing.model import TopicCollection
1313
from graphrag_toolkit.lexical_graph.indexing.constants import TOPICS_KEY
1414
from graphrag_toolkit.lexical_graph.indexing.prompts import EXTRACT_TOPICS_PROMPT
15+
from graphrag_toolkit.lexical_graph.indexing.extract.progress import run_jobs_with_progress
1516
from graphrag_toolkit.lexical_graph.utils.arg_utils import coalesce
1617

1718
from llama_index.core.schema import BaseNode
1819
from llama_index.core.bridge.pydantic import Field
1920
from llama_index.core.extractors.interface import BaseExtractor
2021
from llama_index.core.prompts import PromptTemplate
21-
from llama_index.core.async_utils import run_jobs
2222

2323
logger = logging.getLogger(__name__)
2424

@@ -122,11 +122,13 @@ async def _extract_for_nodes(self, nodes):
122122
jobs = [
123123
self._extract_for_node(node) for node in nodes
124124
]
125-
return await run_jobs(
126-
jobs,
127-
show_progress=self.show_progress,
128-
workers=self.num_workers,
129-
desc=f'Extracting topics [nodes: {len(jobs)}, num_workers: {self.num_workers}]'
125+
return await run_jobs_with_progress(
126+
jobs,
127+
show_progress=self.show_progress,
128+
workers=self.num_workers,
129+
desc=f'Extracting topics [nodes: {len(jobs)}, num_workers: {self.num_workers}]',
130+
total=len(jobs),
131+
logger=logger
130132
)
131133

132134
def _get_metadata_or_default(self, metadata, key, default):

0 commit comments

Comments
 (0)