rich
rich copied to clipboard
Textualize
[BUG] Process causes leftover artifacts in output
- [x] I've checked docs and closed issues for possible solutions.
- [x] I can't find my issue in the FAQ.
Describe the bug
Based on your downloader example, I created a script starting multiple processes in a ThreadPool. If processes fail, I print out the return code and the stderr-output of that process, stop the task and set the process visibility to false to hide that bar.
Sometimes the output contains leftover artifacts of those invisible process bars, probably caused by logging from another worker.
import signal
import subprocess
import random
from threading import Event
from typing import Iterable
from concurrent.futures import ThreadPoolExecutor
from rich.progress import (
BarColumn,
Progress,
TaskID,
TextColumn,
TimeRemainingColumn,
SpinnerColumn,
MofNCompleteColumn
)
progress = Progress(
TextColumn("[bold blue]{task.description}", justify="right"),
BarColumn(),
"[progress.percentage]{task.percentage:>3.1f}%",
"•",
MofNCompleteColumn(separator=" of "),
"•",
TimeRemainingColumn(elapsed_when_finished=True),
SpinnerColumn()
)
done_event = Event()
def handle_sigint(signum, frame):
done_event.set()
signal.signal(signal.SIGINT, handle_sigint)
def execute(task_id: TaskID, commands: Iterable[str]):
"""Execute multiple commands."""
# Set number of commands as total for progress bar
progress.update(task_id, total=len(commands))
for command in commands:
process = subprocess.Popen(
command,
shell=True,
stdin=subprocess.PIPE,
stdout=subprocess.PIPE,
stderr=subprocess.PIPE,
)
# Start the progress bar
progress.start_task(task_id)
# Wait for the process to finish
while True:
return_code = process.poll()
if return_code is not None:
if return_code == 0:
progress.advance(task_id)
break
else:
progress.stop_task(task_id)
progress.update(task_id, visible=False)
progress.console.log(
f"[red bold]Failed[/bold red]: {command} (Return code: {return_code})")
for output in process.stderr.readlines():
progress.console.log(
output.decode().strip(), end="\n\n")
break
if done_event.is_set():
return
def main():
# define a list of dicts with a description of the steps to be executed and an array of commands per step
steps = []
for i in range(random.randint(10, 100)):
commands = []
for j in range(random.randint(1, 10)):
sleep_time = round(random.uniform(0, 0.5), 1)
command = f'sleep {sleep_time} && echo "Running mocked command {j+1}"'
if random.random() < 0.2:
command += ' && idontexist'
commands.append(command)
steps.append({
"description": f"Mocked step {i+1}",
"commands": commands
})
with progress:
with ThreadPoolExecutor(max_workers=4) as pool:
for step in steps:
task_id = progress.add_task(step["description"], start=False)
pool.submit(execute, task_id, commands=step["commands"])
if __name__ == "__main__":
main()
Platform
Click to expand
What platform (Win/Linux/Mac) are you running on? What terminal software are you using? Linux, in a docker container. Using the vscode integrated terminal.
If you're using Rich in a terminal:
╭───────────────────────── <class 'rich.console.Console'> ─────────────────────────╮
│ A high level console interface. │
│ │
│ ╭──────────────────────────────────────────────────────────────────────────────╮ │
│ │ <console width=183 ColorSystem.TRUECOLOR> │ │
│ ╰──────────────────────────────────────────────────────────────────────────────╯ │
│ │
│ color_system = 'truecolor' │
│ encoding = 'utf-8' │
│ file = <_io.TextIOWrapper name='<stdout>' mode='w' encoding='utf-8'> │
│ height = 15 │
│ is_alt_screen = False │
│ is_dumb_terminal = False │
│ is_interactive = True │
│ is_jupyter = False │
│ is_terminal = True │
│ legacy_windows = False │
│ no_color = False │
│ options = ConsoleOptions( │
│ size=ConsoleDimensions(width=183, height=15), │
│ legacy_windows=False, │
│ min_width=1, │
│ max_width=183, │
│ is_terminal=True, │
│ encoding='utf-8', │
│ max_height=15, │
│ justify=None, │
│ overflow=None, │
│ no_wrap=False, │
│ highlight=None, │
│ markup=None, │
│ height=None │
│ ) │
│ quiet = False │
│ record = False │
│ safe_box = True │
│ size = ConsoleDimensions(width=183, height=15) │
│ soft_wrap = False │
│ stderr = False │
│ style = None │
│ tab_size = 8 │
│ width = 183 │
╰──────────────────────────────────────────────────────────────────────────────────╯
╭─── <class 'rich._windows.WindowsConsoleFeatures'> ────╮
│ Windows features available. │
│ │
│ ╭───────────────────────────────────────────────────╮ │
│ │ WindowsConsoleFeatures(vt=False, truecolor=False) │ │
│ ╰───────────────────────────────────────────────────╯ │
│ │
│ truecolor = False │
│ vt = False │
╰───────────────────────────────────────────────────────╯
╭────── Environment Variables ───────╮
│ { │
│ 'TERM': 'xterm-256color', │
│ 'COLORTERM': 'truecolor', │
│ 'CLICOLOR': None, │
│ 'NO_COLOR': None, │
│ 'TERM_PROGRAM': 'vscode', │
│ 'COLUMNS': None, │
│ 'LINES': None, │
│ 'JUPYTER_COLUMNS': None, │
│ 'JUPYTER_LINES': None, │
│ 'JPY_PARENT_PID': None, │
│ 'VSCODE_VERBOSE_LOGGING': None │
│ } │
╰────────────────────────────────────╯
platform="Linux"
rich==13.6.0
I am a system engineer, no developer. I'm sorry if I made a simple rookie mistake...
Output (trimmed some error messages):
[17:39:04] Failed: sleep 0.3 && echo "Running mocked command 1" && idontexist (Return code: 127) new.sh:98
Mocked step 1 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 0.0% • 0 of 2 • -:--:-- ⠴
/bin/sh: 1: idontexist: not found new.sh:103
[17:39:05] Failed: sleep 0.0 && echo "Running mocked command 2" && idontexist (Return code: 127) new.sh:98
/bin/sh: 1: idontexist: not found new.sh:103
Failed: sleep 0.0 && echo "Running mocked command 1" && idontexist (Return code: 127) new.sh:98
/bin/sh: 1: idontexist: not found new.sh:103
[17:39:06] Failed: sleep 0.4 && echo "Running mocked command 2" && idontexist (Return code: 127) new.sh:98
/bin/sh: 1: idontexist: not found new.sh:103
...
[17:39:27] Failed: sleep 0.1 && echo "Running mocked command 5" && idontexist (Return code: 127) new.sh:98
/bin/sh: 1: idontexist: not found new.sh:103
Mocked step 3 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.0% • 3 of 3 • 0:00:00
Mocked step 4 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.0% • 3 of 3 • 0:00:00
Mocked step 8 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.0% • 4 of 4 • 0:00:00
Mocked step 14 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.0% • 10 of 10 • 0:00:02
Mocked step 15 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.0% • 1 of 1 • 0:00:00
Mocked step 17 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.0% • 3 of 3 • 0:00:00
Mocked step 22 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.0% • 1 of 1 • 0:00:00
Mocked step 23 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.0% • 8 of 8 • 0:00:01
Mocked step 24 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.0% • 4 of 4 • 0:00:01
Mocked step 26 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.0% • 3 of 3 • 0:00:01
Mocked step 28 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.0% • 5 of 5 • 0:00:01
Mocked step 29 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.0% • 2 of 2 • 0:00:00
Mocked step 30 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.0% • 6 of 6 • 0:00:01
Mocked step 35 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.0% • 8 of 8 • 0:00:01
Mocked step 37 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.0% • 8 of 8 • 0:00:01
Mocked step 39 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.0% • 2 of 2 • 0:00:00
Mocked step 49 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.0% • 2 of 2 • 0:00:00
Mocked step 51 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.0% • 1 of 1 • 0:00:00
Mocked step 53 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.0% • 4 of 4 • 0:00:00
Mocked step 54 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.0% • 3 of 3 • 0:00:00
Mocked step 58 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.0% • 10 of 10 • 0:00:02
Thank you for your issue. Give us a little time to review it.
PS. You might want to check the FAQ if you haven't done so already.
This is an automated reply, generated by FAQtory
![github-actions[bot] avatar](https://avatars.githubusercontent.com/in/15368?v=4 "Published by a pub.dev verified publisher"){kind=small}
Seems like the artifacts stop if you set it to invisible before stopping it:
progress.update(task_id, visible=False)
progress.stop_task(task_id)
Sorry for the delay, I had no time to follow up on this.
Changing the order to stop after update makes it worse:
You might want to produce a minimally reproducable example for this. Reduce the code to its simplest form that demonstrates the issue. You may find that helps you find the bug, or at least narrows it down. As it stands, this are a bit too many moving parts to offer a suggestion.
I'll try to... it's basically a race-condition created by simultaneously outputting log output and updated/removed progress-bars from different threads, and I'm not really sure how I can create a reliable reproduction without it.
Please stay tuned, I'll be back.
Alright. Small example.
#!/usr/bin/env python3
import time
from rich.progress import Progress
from concurrent.futures import ThreadPoolExecutor
def task(task_obj, advance):
while True:
progress.console.log(f"Task {task_obj}")
progress.console.log(f"Advance {advance}")
progress.update(task_obj, advance=advance)
time.sleep(0.1)
progress = Progress()
with progress:
tasks = [
("Downloading", "red", 0.5),
("Processing", "green", 0.3),
("Cooking", "cyan", 0.9),
("Eating", "magenta", 0.01)
]
with ThreadPoolExecutor(max_workers=4) as pool:
for name, color, advance in tasks:
task_obj = progress.add_task(f"[{color}]{name}...", total=1000)
pool.submit(task, task_obj, advance)
You can interrupt this programm almost right after the start.
A very wild guess: The first thread is already starting while the remainder of the tasks are being added. The log output messes with that.