rich
rich copied to clipboard
Textualize
The process gets stuck (in a deadlock?) when using the RichHandler for logging
Describe the bug
I'm running a multiprocessing + multithreading app, and I was using the RichHandler. The process is a long-running process, and it always got stuck at some point. I was analyzing the dumped stack when the process got in this state using py-spy and I got to the conclusion that the problem is that the RichHandler gets stuck in this line: https://github.com/Textualize/rich/blob/v11.0.0/rich/live.py#L246
If I remove the RichHandler then I don't experience the problem anymore.
This is part of a stack trace of the thread that gets stuck (I removed some calls):
process_renderables (rich/live.py:246)
print (rich/console.py:1600)
emit (rich/logging.py:154)
handle (logging/__init__.py:954)
callHandlers (logging/__init__.py:1661)
handle (logging/__init__.py:1599)
_log (logging/__init__.py:1589)
log (logging/__init__.py:1512)
log_it (tenacity/before_sleep.py:51)
iter (tenacity/__init__.py:373)
__call__ (tenacity/_asyncio.py:48)
async_wrapped (tenacity/_asyncio.py:86)
...
_run (asyncio/events.py:81)
_run_once (asyncio/base_events.py:1859)
run_forever (asyncio/base_events.py:570)
run_until_complete (asyncio/base_events.py:603)
run (asyncio/runners.py:44)
...
run (threading.py:870)
_bootstrap_inner (threading.py:932)
_bootstrap (threading.py:890)
As I told you, the app is using multiprocessing and multithreading and also using rich progress and rich in other parts without problems. It is only the RichHandler the one causing troubles.
Unfortunately, I have no more details. Probably what I gave you is not enough, but well, I just wanted to share in case you get inspired about what could be happening.
Platform Linux with fish cmd
python -m rich.diagnose
╭───────────────────────── <class 'rich.console.Console'> ─────────────────────────╮
│ A high level console interface. │
│ │
│ ╭──────────────────────────────────────────────────────────────────────────────╮ │
│ │ <console width=214 ColorSystem.STANDARD> │ │
│ ╰──────────────────────────────────────────────────────────────────────────────╯ │
│ │
│ color_system = 'standard' │
│ encoding = 'utf-8' │
│ file = <_io.TextIOWrapper name='<stdout>' mode='w' encoding='utf-8'> │
│ height = 45 │
│ 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=214, height=45), │
│ legacy_windows=False, │
│ min_width=1, │
│ max_width=214, │
│ is_terminal=True, │
│ encoding='utf-8', │
│ max_height=45, │
│ justify=None, │
│ overflow=None, │
│ no_wrap=False, │
│ highlight=None, │
│ markup=None, │
│ height=None │
│ ) │
│ quiet = False │
│ record = False │
│ safe_box = True │
│ size = ConsoleDimensions(width=214, height=45) │
│ soft_wrap = False │
│ stderr = False │
│ style = None │
│ tab_size = 8 │
│ width = 214 │
╰──────────────────────────────────────────────────────────────────────────────────╯
pip freeze | grep rich
rich==11.0.0
To finish, thank you very much for Rich. It is an amazing library!
It seems this is not affecting only the RichHandler. I have another hanging process that was not using it. Here is the partial stack trace:
Thread 339 (idle): "MainThread"
process_renderables (rich/live.py:246)
print (rich/console.py:1600)
write (rich/file_proxy.py:47)
_showwarnmsg_impl (warnings.py:30)
_showwarnmsg (warnings.py:112)
convert (PIL/Image.py:975)
_convert_image_to_rgb (clip/clip.py:75)
__call__ (torchvision/transforms/transforms.py:61)
...
fetch (torch/utils/data/_utils/fetch.py:32)
_worker_loop (torch/utils/data/_utils/worker.py:287)
run (multiprocessing/process.py:108)
_bootstrap (multiprocessing/process.py:315)
_launch (multiprocessing/popen_fork.py:75)
__init__ (multiprocessing/popen_fork.py:19)
_Popen (multiprocessing/context.py:277)
_Popen (multiprocessing/context.py:224)
start (multiprocessing/process.py:121)
__init__ (torch/utils/data/dataloader.py:918)
_get_iterator (torch/utils/data/dataloader.py:305)
__iter__ (torch/utils/data/dataloader.py:359)
track (rich/progress.py:701)
...
_run_code (runpy.py:87)
_run_module_as_main (runpy.py:194)
Can you run this on the latest version of Rich. There were deadlock issues in an earlier version, that I thought were fixed.
It's going to be tricky to investigate without any way to reproduce this.
Can you give me an idea of how you are using Rich? Is it always in conjuction with progress bars? I assume you have multiple threads doing logging?
Yes, I know :-(
@willmcgugan Let me explain the processes/threads structure in case it helps.
- The main process that starts a progress bar. It lives during the whole execution.
- Several child subprocesses are started. They will be doing the work. These subprocesses are created by the PyTorch Dataloader. Is not something I do myself.
- Each of these subprocesses starts a thread. So there are two threads per each process. One thread is fetching data using async libraries and the other is consuming the data.
- Any of the threads/processes can emit log messages.
Tried. It is also affecting Ritch 12.0,0
El lun, 14 mar 2022 a las 23:03, Will McGugan @.***>) escribió:
Can you run this on the latest version of Rich. There were deadlock issues in an earlier version, that I thought were fixed.
— Reply to this email directly, view it on GitHub https://github.com/Textualize/rich/issues/2046#issuecomment-1067346008, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAG2V2ERAEUGHEY6WNBBBTTU76ZRTANCNFSM5QM5YOWA . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.
You are receiving this because you authored the thread.Message ID: @.***>
Closing because I haven't managed to reproduce a deadlock with any combination of threads and the logging handler.
Re-open if you have managed to narrow it down to the latest Rich.
![github-actions[bot] avatar](https://avatars.githubusercontent.com/in/15368?v=4 "Published by a pub.dev verified publisher"){kind=small}