Skip to content

Commit 2794c9b

Browse files
committed
fix(util): honour flush_at_end and progress_bar in parallelize
- route each worker thread's stdout to its own buffer instead of rebinding sys.stdout - flush_at_end replays the collected output in input order once the batch ends - progress_bar=False now selects asyncio.gather over tqdm.gather - drop the unreachable dask branch that still held the only uses of both - cover parallelize with 22 offline tests, closes #25 and #154
1 parent fb73aaf commit 2794c9b

2 files changed

Lines changed: 272 additions & 48 deletions

File tree

‎src/osw/utils/util.py‎

Lines changed: 105 additions & 47 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
import asyncio
22
import functools
33
import sys
4+
import threading
45
from asyncio import Queue
56
from concurrent.futures import ThreadPoolExecutor
67
from contextlib import redirect_stdout, suppress
@@ -269,6 +270,61 @@ def wrapper(*args_, **kwargs_):
269270
return decorator(func_=func)
270271

271272

273+
class ThreadRoutedStdout:
274+
"""A stdout stand-in that routes each worker thread's writes to its own buffer
275+
276+
Threads that have not registered a buffer, the calling thread and tqdm among
277+
them, write straight through to the wrapped stream. Installed once for the
278+
duration of a parallelize() call, so unlike contextlib.redirect_stdout it
279+
stays correct while several tasks print at the same time.
280+
"""
281+
282+
def __init__(self, stream: IO):
283+
self.stream = stream
284+
self._local = threading.local()
285+
286+
def register(self) -> List[str]:
287+
"""Gives the calling thread its own buffer and returns it"""
288+
buffer = []
289+
self._local.buffer = buffer
290+
return buffer
291+
292+
def unregister(self):
293+
"""Sends the calling thread's writes back to the wrapped stream"""
294+
self._local.buffer = None
295+
296+
def write(self, message):
297+
buffer = getattr(self._local, "buffer", None)
298+
if buffer is None:
299+
return self.stream.write(message)
300+
buffer.append(message)
301+
return len(message)
302+
303+
def flush(self):
304+
if getattr(self._local, "buffer", None) is None:
305+
self.stream.flush()
306+
307+
def __getattr__(self, name):
308+
# encoding, isatty, fileno and the like stay those of the wrapped stream
309+
return getattr(self.stream, name)
310+
311+
312+
def capture_output(
313+
call: Callable, stdout: ThreadRoutedStdout, sink: List[str], index: int
314+
) -> Callable:
315+
"""Wraps call so that what it prints ends up in sink[index] instead of stdout"""
316+
317+
def wrapper():
318+
buffer = stdout.register()
319+
try:
320+
return call()
321+
finally:
322+
stdout.unregister()
323+
sink[index] = "".join(buffer)
324+
325+
return wrapper
326+
327+
272328
def parallelize(
273329
func: Callable,
274330
iterable: Iterable,
@@ -286,8 +342,10 @@ def parallelize(
286342
iterable:
287343
The iterable, who's items are to be passed as singles to the function.
288344
flush_at_end:
289-
If True, the message buffer will be printed (flushed) to stdout after parallel
290-
execution.
345+
If True, what the tasks print is written to stdout in the order of
346+
``iterable`` once the batch has finished. If False, it is discarded.
347+
Either way it is captured while the tasks run, so that concurrent
348+
printing cannot garble the progress bar.
291349
progress_bar:
292350
If True, a progress bar will be displayed.
293351
return_exceptions:
@@ -299,54 +357,46 @@ def parallelize(
299357
Keyword arguments to be passed to the function.z
300358
"""
301359

302-
MODE = "asyncio"
303-
if MODE == "dask":
304-
# this mode can be removed if asyncio works as expected
305-
with MessageBuffer(flush_at_end) as msg_buf:
306-
tasks = [
307-
dask.delayed(redirect_print_explicitly(func, msg_buf))(item, **kwargs)
308-
for item in iterable
309-
]
310-
print(
311-
f"Performing parallel execution of {func.__name__} ({len(tasks)} tasks)."
360+
items = list(iterable)
361+
# One slot per item, so the collected output can be replayed in input order
362+
# even though the tasks finish in whatever order they finish.
363+
outputs = [""] * len(items)
364+
stdout = ThreadRoutedStdout(sys.stdout)
365+
366+
# run func concurrently with each item in iterable using asyncio
367+
async def _run_tasks():
368+
loop = asyncio.get_event_loop()
369+
# ToDo: handle IO-bound different from CPU-bound tasks
370+
# see https://docs.python.org/3/library/asyncio-eventloop.html#asyncio.loop.run_in_executor
371+
# None => ThreadPoolExecutor for IO-bound tasks
372+
tasks = [
373+
loop.run_in_executor(
374+
None,
375+
capture_output(
376+
functools.partial(func, item, **kwargs), stdout, outputs, index
377+
),
312378
)
313-
if progress_bar:
314-
with ProgressBar():
315-
results = dask.compute(*tasks)
316-
else:
317-
results = dask.compute(*tasks)
379+
for index, item in enumerate(items)
380+
]
381+
print(f"Performing parallel execution of {func.__name__} ({len(tasks)} tasks).")
382+
if return_exceptions:
383+
# tqdm.gather() re-raises the first exception (it has no
384+
# return_exceptions kwarg), which would abandon the remaining
385+
# results. Capture each task's exception instead so the batch
386+
# completes and results stay aligned with the input order.
387+
async def _capture(task):
388+
try:
389+
return await task
390+
except Exception as exc:
391+
return exc
318392

319-
if MODE == "asyncio":
320-
# run func concurrently with each item in iterable using asyncio
321-
async def _run_tasks():
322-
loop = asyncio.get_event_loop()
323-
# ToDo: handle IO-bound different from CPU-bound tasks
324-
# see https://docs.python.org/3/library/asyncio-eventloop.html#asyncio.loop.run_in_executor
325-
# None => ThreadPoolExecutor for IO-bound tasks
326-
tasks = [
327-
loop.run_in_executor(None, functools.partial(func, item, **kwargs))
328-
for item in iterable
329-
]
330-
print(
331-
f"Performing parallel execution of {func.__name__} ({len(tasks)} tasks)."
332-
)
333-
if return_exceptions:
334-
# tqdm.gather() re-raises the first exception (it has no
335-
# return_exceptions kwarg), which would abandon the remaining
336-
# results. Capture each task's exception instead so the batch
337-
# completes and results stay aligned with the input order.
338-
async def _capture(task):
339-
try:
340-
return await task
341-
except Exception as exc:
342-
return exc
343-
344-
tasks = [_capture(task) for task in tasks]
345-
res = await tqdm.gather(
346-
*tasks
347-
) # like asyncio.gather, but with a progress bar
348-
return res
393+
tasks = [_capture(task) for task in tasks]
394+
# tqdm.gather is asyncio.gather plus a progress bar
395+
gather = tqdm.gather if progress_bar else asyncio.gather
396+
return await gather(*tasks)
349397

398+
sys.stdout = stdout
399+
try:
350400
# Check if we are already in an event loop, e.g. in a Jupyter notebook
351401
try:
352402
loop = asyncio.get_running_loop()
@@ -362,6 +412,14 @@ async def _capture(task):
362412
else:
363413
# Starting new event loop
364414
results = asyncio.run(_run_tasks())
415+
finally:
416+
sys.stdout = stdout.stream
417+
if flush_at_end:
418+
# in the finally block, so a failed batch still reports what its
419+
# tasks had to say
420+
for output in outputs:
421+
if output:
422+
print(output, end="")
365423

366424
return results
367425

‎tests/utils/parallelize_test.py‎

Lines changed: 167 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -4,14 +4,18 @@
44
kwargs forwarding, and the two failure modes: abort on the first exception, or
55
collect exceptions in place so the batch completes with results still aligned
66
to the input.
7+
8+
Also covers issue #154: flush_at_end and progress_bar were dropped when the
9+
implementation moved from dask to asyncio, leaving both parameters inert.
710
"""
811

912
import asyncio
13+
import sys
1014
import threading
1115

1216
import pytest
1317

14-
from osw.utils.util import parallelize
18+
from osw.utils.util import ThreadRoutedStdout, parallelize
1519

1620
# Generous enough that a loaded CI machine still passes, short enough that a
1721
# serialized execution trips it instead of hanging the suite.
@@ -112,3 +116,165 @@ async def caller():
112116
return parallelize(_double, [1, 2, 3])
113117

114118
assert asyncio.run(caller()) == [2, 4, 6]
119+
120+
121+
def _print_then_return(item):
122+
print(f"handled {item}")
123+
return item
124+
125+
126+
def test_flush_at_end_prints_what_the_tasks_printed(capsys):
127+
parallelize(_print_then_return, [1, 2, 3], flush_at_end=True)
128+
129+
out = capsys.readouterr().out
130+
assert "handled 1" in out
131+
assert "handled 2" in out
132+
assert "handled 3" in out
133+
134+
135+
def test_flush_at_end_replays_in_input_order(capsys):
136+
"""Output follows the iterable, not the order the tasks happened to finish."""
137+
import time
138+
139+
delays = {1: 0.05, 2: 0.0, 3: 0.03}
140+
141+
def sleep_then_print(item):
142+
time.sleep(delays[item])
143+
print(f"handled {item}")
144+
145+
parallelize(sleep_then_print, [1, 2, 3], flush_at_end=True)
146+
147+
out = capsys.readouterr().out
148+
assert out.index("handled 1") < out.index("handled 2") < out.index("handled 3")
149+
150+
151+
def test_flush_at_end_defers_until_the_batch_is_done():
152+
"""Nothing reaches the real stdout while the tasks are still running."""
153+
written = []
154+
snapshots = []
155+
barrier = threading.Barrier(3, timeout=BARRIER_TIMEOUT)
156+
157+
class _Recorder:
158+
def write(self, message):
159+
written.append(message)
160+
return len(message)
161+
162+
def flush(self):
163+
pass
164+
165+
def print_then_look(item):
166+
print(f"handled {item}")
167+
barrier.wait() # every task has printed by the time this releases
168+
snapshots.append("".join(written))
169+
170+
original = sys.stdout
171+
sys.stdout = _Recorder()
172+
try:
173+
parallelize(print_then_look, [1, 2, 3], flush_at_end=True, progress_bar=False)
174+
finally:
175+
sys.stdout = original
176+
177+
# mid-flight the real stream had seen none of it, afterwards it has all of it
178+
assert not any("handled" in snapshot for snapshot in snapshots)
179+
assert "".join(written).count("handled") == 3
180+
181+
182+
def test_task_output_is_suppressed_without_flush_at_end(capsys):
183+
parallelize(_print_then_return, [1, 2, 3])
184+
185+
assert "handled" not in capsys.readouterr().out
186+
187+
188+
def test_flush_at_end_reports_even_when_the_batch_fails(capsys):
189+
"""A failing item must not swallow the diagnostics of the others."""
190+
191+
def print_then_fail(item):
192+
print(f"handled {item}")
193+
if item == 2:
194+
raise ValueError("boom")
195+
return item
196+
197+
with pytest.raises(ValueError, match="boom"):
198+
parallelize(print_then_fail, [1, 2, 3], flush_at_end=True)
199+
200+
assert "handled 1" in capsys.readouterr().out
201+
202+
203+
def test_stdout_is_restored_afterwards():
204+
original = sys.stdout
205+
206+
parallelize(_print_then_return, [1, 2], flush_at_end=True)
207+
208+
assert sys.stdout is original
209+
210+
211+
def test_stdout_is_restored_after_a_failure():
212+
original = sys.stdout
213+
214+
with pytest.raises(ValueError):
215+
parallelize(_fail_on_even, [2])
216+
217+
assert sys.stdout is original
218+
219+
220+
def test_progress_bar_can_be_switched_off(capsys):
221+
assert parallelize(_double, [1, 2, 3], progress_bar=False) == [2, 4, 6]
222+
223+
# tqdm renders to stderr, so switching it off must leave stderr untouched
224+
assert capsys.readouterr().err == ""
225+
226+
227+
def test_progress_bar_is_shown_by_default(capsys):
228+
assert parallelize(_double, [1, 2, 3]) == [2, 4, 6]
229+
230+
assert "3/3" in capsys.readouterr().err
231+
232+
233+
def test_both_parameters_combine():
234+
"""Neither parameter may break the results the caller is actually after."""
235+
assert parallelize(
236+
_print_then_return, [1, 2, 3], flush_at_end=True, progress_bar=False
237+
) == [1, 2, 3]
238+
239+
240+
def test_routed_stdout_keeps_threads_apart():
241+
"""The property the old redirect_stdout lacked: concurrent writes stay separate."""
242+
stdout = ThreadRoutedStdout(sys.stdout)
243+
collected = {}
244+
barrier = threading.Barrier(2, timeout=BARRIER_TIMEOUT)
245+
246+
def write_interleaved(name):
247+
buffer = stdout.register()
248+
barrier.wait() # force both threads to be inside their capture at once
249+
stdout.write(name)
250+
barrier.wait()
251+
stdout.write(name)
252+
stdout.unregister()
253+
collected[name] = "".join(buffer)
254+
255+
threads = [
256+
threading.Thread(target=write_interleaved, args=(name,)) for name in ("a", "b")
257+
]
258+
for thread in threads:
259+
thread.start()
260+
for thread in threads:
261+
thread.join()
262+
263+
assert collected == {"a": "aa", "b": "bb"}
264+
265+
266+
def test_routed_stdout_passes_unregistered_threads_through():
267+
class _Sink:
268+
def __init__(self):
269+
self.written = []
270+
271+
def write(self, message):
272+
self.written.append(message)
273+
return len(message)
274+
275+
sink = _Sink()
276+
stdout = ThreadRoutedStdout(sink)
277+
278+
stdout.write("straight through")
279+
280+
assert sink.written == ["straight through"]

0 commit comments

Comments
 (0)